See
<https://builds.apache.org/job/Blur-master-jdk7/org.apache.blur$blur-mapred-hadoop1/1181/>
------------------------------------------
[...truncated 714 lines...]
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:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
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)
INFO 20141209_22:20:51:109_UTC [Watch Children
[/blur/clusters/default/online-nodes][fe73d21d-d354-458c-9492-91fdb7e473a2]]
indexserver.DistributedIndexServer: Node went offline [pomona.apache.org:60511]
INFO 20141209_22:20:51:110_UTC [Watch Children
[/blur/clusters/default/online-nodes][fe73d21d-d354-458c-9492-91fdb7e473a2]]
indexserver.DistributedIndexServer: Online shard servers changed, clearing
layout managers and cache.
WARN 20141209_22:20:51:111_UTC [main] zookeeper.WatchChildren: Closing
[fe73d21d-d354-458c-9492-91fdb7e473a2]
WARN 20141209_22:20:51:113_UTC [main] zookeeper.WatchChildren: Closing
[618395fa-7cd4-48aa-9772-720a9053bb76]
WARN 20141209_22:20:51:113_UTC [main] zookeeper.WatchChildren: Closing
[c0c3802a-ad80-4265-9353-584671e03d69]
INFO 20141209_22:20:51:114_UTC [ProcessThread(sid:0 cport:-1):]
server.PrepRequestProcessor: Processed session termination for sessionid:
0x14a3121e4bf0005
INFO 20141209_22:20:51:115_UTC [main] zookeeper.ZooKeeper: Session:
0x14a3121e4bf0005 closed
INFO 20141209_22:20:51:115_UTC [pool-3-thread-3-EventThread]
zookeeper.ClientCnxn: EventThread shut down
INFO 20141209_22:20:51:115_UTC [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0]
server.NIOServerCnxn: Closed socket connection for client /67.195.81.187:39795
which had sessionid 0x14a3121e4bf0005
WARN 20141209_22:20:51:119_UTC [main] zookeeper.WatchChildren: Closing
[0db7df3d-4af5-497f-9fc1-898933debb42]
WARN 20141209_22:20:51:120_UTC [main] zookeeper.WatchChildren: Closing
[030f46a2-c907-4177-9b3e-4d58d363ded2]
WARN 20141209_22:20:51:120_UTC [main] zookeeper.WatchChildren: Closing
[cabcc1e3-d418-470b-9aac-6abf90a78dcc]
WARN 20141209_22:20:51:120_UTC [main] zookeeper.WatchNodeExistance: Closing
[179c936e-5bd1-4a9e-bee3-2bc5117b7ff9]
WARN 20141209_22:20:51:120_UTC [main] zookeeper.WatchChildren: Closing
[46a4eae1-2349-46cf-b854-1cdeba4d8f63]
WARN 20141209_22:20:51:120_UTC [main] zookeeper.WatchChildren: Closing
[4496c083-da97-47bd-965f-ea5965ab3099]
WARN 20141209_22:20:51:120_UTC [main] zookeeper.WatchChildren: Closing
[124b4000-6fbf-4698-933b-d9deb393743e]
INFO 20141209_22:20:51:121_UTC [ProcessThread(sid:0 cport:-1):]
server.PrepRequestProcessor: Processed session termination for sessionid:
0x14a3121e4bf0001
INFO 20141209_22:20:51:121_UTC [main] zookeeper.ZooKeeper: Session:
0x14a3121e4bf0001 closed
INFO 20141209_22:20:51:121_UTC [main-EventThread] zookeeper.ClientCnxn:
EventThread shut down
INFO 20141209_22:20:51:122_UTC [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0]
server.NIOServerCnxn: Closed socket connection for client /67.195.81.187:39791
which had sessionid 0x14a3121e4bf0001
WARN 20141209_22:20:51:123_UTC [main] zookeeper.WatchChildren: Closing
[e2e29089-d9ea-4aec-9b96-a91a775b2c99]
WARN 20141209_22:20:51:123_UTC [main] zookeeper.WatchChildren: Closing
[f746c080-a689-4e24-aa7e-4178ede86b3f]
WARN 20141209_22:20:51:124_UTC [main] zookeeper.WatchChildren: Closing
[8d9ddb59-3c9b-49fd-9f2e-c495f6a42bad]
WARN 20141209_22:20:51:124_UTC [main] zookeeper.WatchNodeExistance: Closing
[95dfa0ce-8bed-4ee0-a41d-6e177b70f433]
WARN 20141209_22:20:51:124_UTC [main] zookeeper.WatchChildren: Closing
[2e4dfc23-6a96-4a7b-8b32-59cde58c64f5]
WARN 20141209_22:20:51:125_UTC [main] zookeeper.WatchChildren: Closing
[d682a2a5-d6a3-4b00-9710-a2c8365a78ca]
WARN 20141209_22:20:51:125_UTC [main] zookeeper.WatchChildren: Closing
[71234fe1-4b7c-4f27-ab0e-d88459f4b55f]
INFO 20141209_22:20:51:125_UTC [ProcessThread(sid:0 cport:-1):]
server.PrepRequestProcessor: Processed session termination for sessionid:
0x14a3121e4bf0002
INFO 20141209_22:20:51:126_UTC [main] zookeeper.ZooKeeper: Session:
0x14a3121e4bf0002 closed
INFO 20141209_22:20:51:126_UTC [main-EventThread] zookeeper.ClientCnxn:
EventThread shut down
INFO 20141209_22:20:51:126_UTC [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0]
server.NIOServerCnxn: Closed socket connection for client /67.195.81.187:39792
which had sessionid 0x14a3121e4bf0002
INFO 20141209_22:20:51:127_UTC [NIOServerCxn.Factory:0.0.0.0/0.0.0.0:0]
server.NIOServerCnxnFactory: NIOServerCnxn factory exited run method
INFO 20141209_22:20:51:128_UTC [main] server.ZooKeeperServer: shutting down
INFO 20141209_22:20:51:128_UTC [Thread-45] server.ZooKeeperServer: shutting
down
INFO 20141209_22:20:51:128_UTC [main] server.SessionTrackerImpl: Shutting down
INFO 20141209_22:20:51:128_UTC [Thread-45] server.SessionTrackerImpl: Shutting
down
INFO 20141209_22:20:51:128_UTC [main] server.PrepRequestProcessor: Shutting
down
INFO 20141209_22:20:51:128_UTC [Thread-45] server.PrepRequestProcessor:
Shutting down
INFO 20141209_22:20:51:128_UTC [ProcessThread(sid:0 cport:-1):]
server.PrepRequestProcessor: PrepRequestProcessor exited loop!
INFO 20141209_22:20:51:128_UTC [main] server.SyncRequestProcessor: Shutting
down
INFO 20141209_22:20:51:128_UTC [Thread-45] server.SyncRequestProcessor:
Shutting down
INFO 20141209_22:20:51:129_UTC [SyncThread:0] server.SyncRequestProcessor:
SyncRequestProcessor exited!
INFO 20141209_22:20:51:129_UTC [Thread-45] server.FinalRequestProcessor:
shutdown of request processor complete
INFO 20141209_22:20:51:129_UTC [main] server.FinalRequestProcessor: shutdown
of request processor complete
WARN 20141209_22:20:51:130_UTC [main] jmx.MBeanRegistry: Failed to unregister
MBean InMemoryDataTree
WARN 20141209_22:20:51:130_UTC [main] jmx.MBeanRegistry: Error during
unregister
javax.management.InstanceNotFoundException:
org.apache.ZooKeeperService:name0=StandaloneServer_port-1,name1=InMemoryDataTree
at
com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.getMBean(DefaultMBeanServerInterceptor.java:1095)
at
com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.exclusiveUnregisterMBean(DefaultMBeanServerInterceptor.java:427)
at
com.sun.jmx.interceptor.DefaultMBeanServerInterceptor.unregisterMBean(DefaultMBeanServerInterceptor.java:415)
at
com.sun.jmx.mbeanserver.JmxMBeanServer.unregisterMBean(JmxMBeanServer.java:546)
at
org.apache.zookeeper.jmx.MBeanRegistry.unregister(MBeanRegistry.java:115)
at
org.apache.zookeeper.jmx.MBeanRegistry.unregister(MBeanRegistry.java:132)
at
org.apache.zookeeper.server.ZooKeeperServer.unregisterJMX(ZooKeeperServer.java:443)
at
org.apache.zookeeper.server.ZooKeeperServer.shutdown(ZooKeeperServer.java:436)
at
org.apache.zookeeper.server.NIOServerCnxnFactory.shutdown(NIOServerCnxnFactory.java:271)
at
org.apache.zookeeper.server.ZooKeeperServerMain.shutdown(ZooKeeperServerMain.java:127)
at
org.apache.blur.zookeeper.ZkMiniCluster$ZooKeeperServerMainEmbedded.shutdown(ZkMiniCluster.java:94)
at
org.apache.blur.zookeeper.ZkMiniCluster.shutdownZooKeeper(ZkMiniCluster.java:191)
at org.apache.blur.MiniCluster.shutdownZooKeeper(MiniCluster.java:450)
at org.apache.blur.MiniCluster.shutdownBlurCluster(MiniCluster.java:176)
at
org.apache.blur.mapreduce.lib.BlurOutputFormatMiniClusterTest.teardown(BlurOutputFormatMiniClusterTest.java:114)
at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
at
sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
at
org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:44)
at
org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15)
at
org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:41)
at
org.junit.internal.runners.statements.RunAfters.evaluate(RunAfters.java:37)
at org.junit.runners.ParentRunner.run(ParentRunner.java:292)
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:57)
at
sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
at java.lang.reflect.Method.invoke(Method.java:606)
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)
INFO 20141209_22:20:51:131_UTC [main] blur.MiniCluster: Shutting down Mini DFS
Shutting down the Mini HDFS Cluster
Shutting down DataNode 0
INFO 20141209_22:20:51:131_UTC [main] mortbay.log: Stopped
SelectChannelConnector@localhost:0
INFO 20141209_22:20:52:000_UTC [SessionTracker] server.SessionTrackerImpl:
SessionTrackerImpl exited loop!
INFO 20141209_22:20:52:235_UTC [main] mortbay.log: Stopped
SelectChannelConnector@localhost:0
INFO 20141209_22:20:52:347_UTC [main] blur.MiniCluster: Shutting down
FileSystem
INFO 20141209_22:20:52:348_UTC [main] blur.MiniCluster: Stopping
ThreadPoolExecutor [pool-1-thread-1]
INFO 20141209_22:20:52:348_UTC [main] blur.MiniCluster: Waiting for thread
pool to exit [pool-1-thread-1]
INFO 20141209_22:20:52:348_UTC [main] blur.MiniCluster: Stopping
ThreadPoolExecutor [pool-2-thread-1]
INFO 20141209_22:20:52:348_UTC [main] blur.MiniCluster: Waiting for thread
pool to exit [pool-2-thread-1]
INFO 20141209_22:20:52:348_UTC [main] blur.MiniCluster: Stopping
ThreadPoolExecutor [pool-3-thread-1]
INFO 20141209_22:20:52:348_UTC [main] blur.MiniCluster: Waiting for thread
pool to exit [pool-3-thread-1]
INFO 20141209_22:20:52:349_UTC [main] blur.MiniCluster: Stopping
ThreadPoolExecutor [pool-5-thread-1]
INFO 20141209_22:20:52:349_UTC [main] blur.MiniCluster: Waiting for thread
pool to exit [pool-5-thread-1]
INFO 20141209_22:20:52:349_UTC [main] blur.MiniCluster: Stopping
ThreadPoolExecutor [pool-7-thread-1]
INFO 20141209_22:20:52:349_UTC [main] blur.MiniCluster: Waiting for thread
pool to exit [pool-7-thread-1]
INFO 20141209_22:20:52:349_UTC [main] blur.MiniCluster: Stopping
ThreadPoolExecutor [pool-6-thread-1]
INFO 20141209_22:20:52:349_UTC [main] blur.MiniCluster: Waiting for thread
pool to exit [pool-6-thread-1]
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 143.251 sec
INFO 20141209_22:20:52:353_UTC [Thread-178] indexserver.BlurServerShutDown:
Closing zookeeper.
INFO 20141209_22:20:52:353_UTC [Thread-66] indexserver.BlurServerShutDown:
Closing zookeeper.
INFO 20141209_22:20:52:354_UTC [Thread-54] indexserver.BlurServerShutDown:
Closing zookeeper.
INFO 20141209_22:20:52:355_UTC [Thread-182] indexserver.BlurServerShutDown:
Closing zookeeper.
INFO 20141209_22:20:52:355_UTC [Thread-176] indexserver.BlurServerShutDown:
Closing zookeeper.
Running org.apache.blur.mapreduce.lib.v2.DirectIndexingDriverMiniClusterTest
Generating rack names for tasktrackers
Generating host names for tasktrackers
INFO 20141209_22:20:57:819_UTC [Thread-1] mortbay.log: Logging to
org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via org.mortbay.log.Slf4jLog
INFO 20141209_22:20:57:888_UTC [Thread-1] mortbay.log: jetty-6.1.26
INFO 20141209_22:20:57:926_UTC [Thread-1] mortbay.log: Extract
jar:file:/home/jenkins/jenkins-slave/maven-repositories/1/org/apache/hadoop/hadoop-core/1.2.1/hadoop-core-1.2.1.jar!/webapps/job
to /tmp/Jetty_localhost_60089_job____mi91mf/webapp
INFO 20141209_22:20:58:253_UTC [Thread-1] mortbay.log: Started
SelectChannelConnector@localhost:60089
INFO 20141209_22:21:13:463_UTC [main] mortbay.log: jetty-6.1.26
INFO 20141209_22:21:13:479_UTC [main] mortbay.log: Extract
jar:file:/home/jenkins/jenkins-slave/maven-repositories/1/org/apache/hadoop/hadoop-core/1.2.1/hadoop-core-1.2.1.jar!/webapps/task
to /tmp/Jetty_0_0_0_0_41497_task____lejc2b/webapp
INFO 20141209_22:21:13:688_UTC [main] mortbay.log: Started
[email protected]:41497
INFO 20141209_22:21:14:794_UTC [main] mortbay.log: Stopped
[email protected]:0
INFO 20141209_22:21:14:910_UTC [main] mortbay.log: Stopped
SelectChannelConnector@localhost:0
Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 22.425 sec
Running org.apache.blur.mapreduce.lib.BlurOutputFormatTest
Generating rack names for tasktrackers
Generating host names for tasktrackers
INFO 20141209_22:21:23:860_UTC [Thread-1] mortbay.log: Logging to
org.slf4j.impl.Log4jLoggerAdapter(org.mortbay.log) via org.mortbay.log.Slf4jLog
INFO 20141209_22:21:23:930_UTC [Thread-1] mortbay.log: jetty-6.1.26
INFO 20141209_22:21:23:971_UTC [Thread-1] mortbay.log: Extract
jar:file:/home/jenkins/jenkins-slave/maven-repositories/1/org/apache/hadoop/hadoop-core/1.2.1/hadoop-core-1.2.1.jar!/webapps/job
to /tmp/Jetty_localhost_55815_job____ariez6/webapp
INFO 20141209_22:21:24:295_UTC [Thread-1] mortbay.log: Started
SelectChannelConnector@localhost:55815
INFO 20141209_22:21:33:483_UTC [main] mortbay.log: jetty-6.1.26
INFO 20141209_22:21:33:499_UTC [main] mortbay.log: Extract
jar:file:/home/jenkins/jenkins-slave/maven-repositories/1/org/apache/hadoop/hadoop-core/1.2.1/hadoop-core-1.2.1.jar!/webapps/task
to /tmp/Jetty_0_0_0_0_52305_task____.4mg2zr/webapp
INFO 20141209_22:21:33:722_UTC [main] mortbay.log: Started
[email protected]:52305
WARN 20141209_22:21:34:868_UTC [main] lib.BlurMapReduceUtil: Could not find
jar for class class org.apache.blur.mapreduce.lib.BlurMutate in order to ship
it to the cluster.
WARN 20141209_22:21:34:869_UTC [main] lib.BlurMapReduceUtil: Could not find
jar for class class org.apache.blur.mapreduce.lib.BlurMutate in order to ship
it to the cluster.
WARN 20141209_22:21:34:870_UTC [main] lib.BlurMapReduceUtil: Could not find
jar for class class org.apache.blur.mapreduce.lib.BlurOutputFormat in order to
ship it to the cluster.
Counters: Counters: 37
FileSystemCounters
FILE_BYTES_READ=1176
FILE_BYTES_WRITTEN=151143
org.apache.blur.mapreduce.lib.BlurCounters
COLUMN_COUNT=4
COPY_RATE=0
LUCENE_FIELD_COUNT=12
RECORD_COUNT=4
RECORD_DUPLICATE_COUNT=0
RECORD_RATE=0
ROW_COUNT=2
ROW_DELETE_COUNT=0
ROW_OVERFLOW_COUNT=0
ROW_RATE=0
Job Counters
Total time spent by all maps waiting after reserving slots
(ms)=0
Total time spent by all reduces waiting after reserving slots
(ms)=0
Rack-local map tasks=2
SLOTS_MILLIS_MAPS=37796
SLOTS_MILLIS_REDUCES=11157
Launched map tasks=2
Launched reduce tasks=1
Map-Reduce Framework
Combine input records=0
Combine output records=0
Total committed heap usage (bytes)=416940032
CPU time spent (ms)=3240
Map input records=2
Map output bytes=58
Map output materialized bytes=74
Map output records=2
Physical memory (bytes) snapshot=456536064
Reduce input groups=1
Reduce input records=2
Reduce output records=2
Reduce shuffle bytes=74
Spilled Records=4
SPLIT_RAW_BYTES=378
Virtual memory (bytes) snapshot=1301389312
File Input Format Counters
Bytes Read=66
File Output Format Counters
Bytes Written=0
WARN 20141209_22:22:07:785_UTC [main] lib.BlurMapReduceUtil: Could not find
jar for class class org.apache.blur.mapreduce.lib.BlurMutate in order to ship
it to the cluster.
WARN 20141209_22:22:07:786_UTC [main] lib.BlurMapReduceUtil: Could not find
jar for class class org.apache.blur.mapreduce.lib.BlurMutate in order to ship
it to the cluster.
WARN 20141209_22:22:07:787_UTC [main] lib.BlurMapReduceUtil: Could not find
jar for class class org.apache.blur.mapreduce.lib.BlurOutputFormat in order to
ship it to the cluster.
Counters: Counters: 37
FileSystemCounters
FILE_BYTES_READ=10314737
FILE_BYTES_WRITTEN=8067275
org.apache.blur.mapreduce.lib.BlurCounters
COLUMN_COUNT=160000
COPY_RATE=0
LUCENE_FIELD_COUNT=480000
RECORD_COUNT=160000
RECORD_DUPLICATE_COUNT=0
RECORD_RATE=0
ROW_COUNT=52
ROW_DELETE_COUNT=0
ROW_OVERFLOW_COUNT=50
ROW_RATE=0
Job Counters
Total time spent by all maps waiting after reserving slots
(ms)=0
Total time spent by all reduces waiting after reserving slots
(ms)=0
Rack-local map tasks=2
SLOTS_MILLIS_MAPS=48489
SLOTS_MILLIS_REDUCES=27138
Launched map tasks=2
Launched reduce tasks=2
Map-Reduce Framework
Combine input records=0
Combine output records=0
Total committed heap usage (bytes)=595853312
CPU time spent (ms)=30990
Map input records=80000
Map output bytes=2635850
Map output materialized bytes=2795874
Map output records=80000
Physical memory (bytes) snapshot=682270720
Reduce input groups=50
Reduce input records=80000
Reduce output records=80000
Reduce shuffle bytes=2795874
Spilled Records=160000
SPLIT_RAW_BYTES=378
Virtual memory (bytes) snapshot=1752195072
File Input Format Counters
Bytes Read=1945350
File Output Format Counters
Bytes Written=0
WARN 20141209_22:23:03:581_UTC [main] lib.BlurMapReduceUtil: Could not find
jar for class class org.apache.blur.mapreduce.lib.BlurMutate in order to ship
it to the cluster.
WARN 20141209_22:23:03:583_UTC [main] lib.BlurMapReduceUtil: Could not find
jar for class class org.apache.blur.mapreduce.lib.BlurMutate in order to ship
it to the cluster.
WARN 20141209_22:23:03:584_UTC [main] lib.BlurMapReduceUtil: Could not find
jar for class class org.apache.blur.mapreduce.lib.BlurOutputFormat in order to
ship it to the cluster.
Killed
Running org.apache.blur.mapreduce.lib.CsvBlurMapperTest
Tests run: 5, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 2.713 sec
Results :
Tests run: 12, Failures: 0, Errors: 0, Skipped: 0
[JENKINS] Recording test results
