Established TCP socket on 42396 <===[JENKINS REMOTING CAPACITY]===>channel started Executing Maven: -B -f /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/pom.xml clean install javadoc:javadoc [INFO] Scanning for projects... [WARNING] [WARNING] Some problems were encountered while building the effective model for org.dataone:d1_cn_index_generator:jar:2.3.3 [WARNING] 'build.plugins.plugin.version' for org.apache.maven.plugins:maven-compiler-plugin is missing. @ line 182, column 21 [WARNING] 'build.plugins.plugin.version' for org.codehaus.mojo:buildnumber-maven-plugin is missing. @ line 190, column 21 [WARNING] [WARNING] It is highly recommended to fix these problems because they threaten the stability of your build. [WARNING] [WARNING] For this reason, future Maven versions might no longer support building such malformed projects. [WARNING] [INFO] [INFO] ------------------------------------------------------------------------ [INFO] Building DataONE Index Task Generator 2.3.3 [INFO] ------------------------------------------------------------------------ [INFO] [INFO] --- maven-clean-plugin:2.3:clean (default-clean) @ d1_cn_index_generator --- [INFO] [INFO] --- buildnumber-maven-plugin:1.4:create (default) @ d1_cn_index_generator --- [INFO] Executing: /bin/sh -c cd '/var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace' && 'svn' '--non-interactive' 'info' [INFO] Working directory: /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace [INFO] Storing buildNumber: 19418 at timestamp: 1540586700495 [INFO] Executing: /bin/sh -c cd '/var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace' && 'svn' '--non-interactive' 'info' [INFO] Working directory: /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace [INFO] Storing buildScmBranch: tags/D1_CN_INDEX_GENERATOR_v2.3.3 [INFO] [INFO] --- maven-resources-plugin:2.3:resources (default-resources) @ d1_cn_index_generator --- [INFO] Using 'UTF-8' encoding to copy filtered resources. [INFO] Copying 1 resource [INFO] Copying 5 resources [INFO] [INFO] --- maven-compiler-plugin:2.0.2:compile (default-compile) @ d1_cn_index_generator --- [INFO] Compiling 4 source files to /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/classes [INFO] [INFO] --- maven-resources-plugin:2.3:testResources (default-testResources) @ d1_cn_index_generator --- [INFO] Using 'UTF-8' encoding to copy filtered resources. [INFO] Copying 7 resources [INFO] [INFO] --- maven-compiler-plugin:2.0.2:testCompile (default-testCompile) @ d1_cn_index_generator --- [INFO] Compiling 3 source files to /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/test-classes [INFO] [INFO] --- maven-surefire-plugin:2.10:test (default-test) @ d1_cn_index_generator --- [INFO] Surefire report directory: /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/surefire-reports ------------------------------------------------------- T E S T S ------------------------------------------------------- Running org.dataone.cn.index.test.IndexTaskGeneratorEntryListenerTest 2018-10-26 20:45:02,331 INFO [org.springframework.test.context.TestContextManager] - @TestExecutionListeners is not present for class [class org.dataone.cn.index.test.IndexTaskGeneratorEntryListenerTest]: using defaults. 2018-10-26 20:45:02,469 ERROR [org.dataone.configuration.Settings] - Problem loading configuration: file:/var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/classes/org/dataone/configuration/config.xml org.apache.commons.configuration.ConfigurationException: org.apache.commons.configuration.ConfigurationRuntimeException: org.apache.commons.configuration.ConfigurationException: Cannot locate configuration source file:///etc/dataone/index/d1client.properties at org.apache.commons.configuration.DefaultConfigurationBuilder.createConfigurationAt(DefaultConfigurationBuilder.java:849) at org.apache.commons.configuration.DefaultConfigurationBuilder.initCombinedConfiguration(DefaultConfigurationBuilder.java:699) at org.apache.commons.configuration.DefaultConfigurationBuilder.getConfiguration(DefaultConfigurationBuilder.java:601) at org.apache.commons.configuration.DefaultConfigurationBuilder.getConfiguration(DefaultConfigurationBuilder.java:566) at org.dataone.configuration.Settings.getConfiguration(Settings.java:106) at org.dataone.cn.index.test.IndexTaskGeneratorEntryListenerTest.<clinit>(IndexTaskGeneratorEntryListenerTest.java:63) at sun.reflect.NativeConstructorAccessorImpl.newInstance0(Native Method) at sun.reflect.NativeConstructorAccessorImpl.newInstance(NativeConstructorAccessorImpl.java:62) at sun.reflect.DelegatingConstructorAccessorImpl.newInstance(DelegatingConstructorAccessorImpl.java:45) at java.lang.reflect.Constructor.newInstance(Constructor.java:423) at org.junit.runners.BlockJUnit4ClassRunner.createTest(BlockJUnit4ClassRunner.java:187) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.createTest(SpringJUnit4ClassRunner.java:210) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner$1.runReflectiveCall(SpringJUnit4ClassRunner.java:288) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.methodBlock(SpringJUnit4ClassRunner.java:290) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:231) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222) at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61) at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:71) at org.junit.runners.ParentRunner.run(ParentRunner.java:300) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:174) at org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:53) at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:123) at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:104) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:164) at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:110) at org.apache.maven.surefire.booter.SurefireStarter.invokeProvider(SurefireStarter.java:175) at org.apache.maven.surefire.booter.SurefireStarter.runSuitesInProcessWhenForked(SurefireStarter.java:107) at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:68) Caused by: org.apache.commons.configuration.ConfigurationRuntimeException: org.apache.commons.configuration.ConfigurationException: Cannot locate configuration source file:///etc/dataone/index/d1client.properties at org.apache.commons.configuration.beanutils.BeanHelper.createBean(BeanHelper.java:335) at org.apache.commons.configuration.beanutils.BeanHelper.createBean(BeanHelper.java:352) at org.apache.commons.configuration.beanutils.BeanHelper.createBean(BeanHelper.java:366) at org.apache.commons.configuration.DefaultConfigurationBuilder.createConfigurationAt(DefaultConfigurationBuilder.java:844) ... 37 more Caused by: org.apache.commons.configuration.ConfigurationException: Cannot locate configuration source file:///etc/dataone/index/d1client.properties at org.apache.commons.configuration.AbstractFileConfiguration.load(AbstractFileConfiguration.java:249) at org.apache.commons.configuration.AbstractFileConfiguration.load(AbstractFileConfiguration.java:229) at org.apache.commons.configuration.DefaultConfigurationBuilder$FileConfigurationProvider.getConfiguration(DefaultConfigurationBuilder.java:1419) at org.apache.commons.configuration.DefaultConfigurationBuilder$ConfigurationBeanFactory.createBean(DefaultConfigurationBuilder.java:1308) at org.apache.commons.configuration.beanutils.BeanHelper.createBean(BeanHelper.java:330) ... 40 more 2018-10-26 20:45:02,547 INFO [org.springframework.beans.factory.xml.XmlBeanDefinitionReader] - Loading XML bean definitions from class path resource [org/dataone/cn/index/test/test-context.xml] 2018-10-26 20:45:02,642 INFO [org.springframework.beans.factory.xml.XmlBeanDefinitionReader] - Loading XML bean definitions from class path resource [generator-context.xml] 2018-10-26 20:45:02,661 INFO [org.springframework.beans.factory.xml.XmlBeanDefinitionReader] - Loading XML bean definitions from class path resource [task-index-context.xml] 2018-10-26 20:45:02,747 INFO [org.springframework.beans.factory.xml.XmlBeanDefinitionReader] - Loading XML bean definitions from class path resource [org/dataone/configuration/postgres-datasource.xml] 2018-10-26 20:45:02,812 INFO [org.springframework.beans.factory.xml.XmlBeanDefinitionReader] - Loading XML bean definitions from class path resource [org/dataone/configuration/hsql-datasource.xml] 2018-10-26 20:45:02,823 INFO [org.springframework.beans.factory.support.DefaultListableBeanFactory] - Overriding bean definition for bean 'jpaVendorAdapter': replacing [Generic bean: class [org.springframework.orm.jpa.vendor.HibernateJpaVendorAdapter]; scope=; abstract=false; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=null; factoryMethodName=null; initMethodName=null; destroyMethodName=null; defined in class path resource [org/dataone/configuration/postgres-datasource.xml]] with [Generic bean: class [org.springframework.orm.jpa.vendor.HibernateJpaVendorAdapter]; scope=; abstract=false; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=null; factoryMethodName=null; initMethodName=null; destroyMethodName=null; defined in class path resource [org/dataone/configuration/hsql-datasource.xml]] 2018-10-26 20:45:02,826 INFO [org.springframework.beans.factory.support.DefaultListableBeanFactory] - Overriding bean definition for bean 'dataSource': replacing [Generic bean: class [org.apache.commons.dbcp.BasicDataSource]; scope=; abstract=false; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=null; factoryMethodName=null; initMethodName=null; destroyMethodName=close; defined in class path resource [org/dataone/configuration/postgres-datasource.xml]] with [Root bean: class [org.springframework.jdbc.datasource.embedded.EmbeddedDatabaseFactoryBean]; scope=; abstract=false; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=null; factoryMethodName=null; initMethodName=null; destroyMethodName=null] 2018-10-26 20:45:02,827 INFO [org.springframework.beans.factory.support.DefaultListableBeanFactory] - Overriding bean definition for bean 'indexTaskGeneratorEntryListener': replacing [Generic bean: class [org.dataone.cn.index.generator.IndexTaskGeneratorEntryListener]; scope=; abstract=false; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=null; factoryMethodName=null; initMethodName=null; destroyMethodName=null; defined in class path resource [generator-context.xml]] with [Generic bean: class [org.dataone.cn.index.generator.IndexTaskGeneratorEntryListener]; scope=; abstract=false; lazyInit=false; autowireMode=0; dependencyCheck=0; autowireCandidate=true; primary=false; factoryBeanName=null; factoryMethodName=null; initMethodName=null; destroyMethodName=null; defined in class path resource [org/dataone/cn/index/test/test-context.xml]] 2018-10-26 20:45:02,829 INFO [org.springframework.context.support.GenericApplicationContext] - Refreshing org.springframework.context.support.GenericApplicationContext@5e57643e: startup date [Fri Oct 26 20:45:02 UTC 2018]; root of context hierarchy 2018-10-26 20:45:02,897 INFO [org.springframework.beans.factory.config.PropertyPlaceholderConfigurer] - Loading properties file from class path resource [org/dataone/configuration/jdbc.properties] 2018-10-26 20:45:02,943 INFO [org.springframework.jdbc.datasource.embedded.EmbeddedDatabaseFactory] - Creating embedded database 'dataSource' 2018-10-26 20:45:02,976 INFO [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean] - Building JPA container EntityManagerFactory for persistence unit 'default' 2018-10-26 20:45:03,054 INFO [org.hibernate.annotations.common.Version] - Hibernate Commons Annotations 3.2.0.Final 2018-10-26 20:45:03,058 INFO [org.hibernate.cfg.Environment] - Hibernate 3.6.10.Final 2018-10-26 20:45:03,059 INFO [org.hibernate.cfg.Environment] - hibernate.properties not found 2018-10-26 20:45:03,062 INFO [org.hibernate.cfg.Environment] - Bytecode provider name : javassist 2018-10-26 20:45:03,064 INFO [org.hibernate.cfg.Environment] - using JDK 1.4 java.sql.Timestamp handling 2018-10-26 20:45:03,111 INFO [org.hibernate.ejb.Version] - Hibernate EntityManager 3.6.10.Final 2018-10-26 20:45:03,119 INFO [org.hibernate.ejb.Ejb3Configuration] - Processing PersistenceUnitInfo [ name: default ...] 2018-10-26 20:45:03,173 INFO [org.hibernate.cfg.AnnotationBinder] - Binding entity from annotated class: org.dataone.cn.index.task.IndexTask 2018-10-26 20:45:03,194 INFO [org.hibernate.cfg.annotations.EntityBinder] - Bind entity org.dataone.cn.index.task.IndexTask on table index_task 2018-10-26 20:45:03,224 INFO [org.hibernate.cfg.Configuration] - Hibernate Validator not found: ignoring 2018-10-26 20:45:03,236 INFO [org.hibernate.cfg.search.HibernateSearchEventListenerRegister] - Unable to find org.hibernate.search.event.FullTextIndexEventListener on the classpath. Hibernate Search is not enabled. 2018-10-26 20:45:03,239 INFO [org.hibernate.connection.ConnectionProviderFactory] - Initializing connection provider: org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider 2018-10-26 20:45:03,241 INFO [org.hibernate.ejb.connection.InjectedDataSourceConnectionProvider] - Using provided datasource 2018-10-26 20:45:03,366 INFO [org.hibernate.dialect.Dialect] - Using dialect: org.hibernate.dialect.H2Dialect 2018-10-26 20:45:03,373 INFO [org.hibernate.engine.jdbc.JdbcSupportLoader] - Disabling contextual LOB creation as JDBC driver reported JDBC version [3] less than 4 2018-10-26 20:45:03,373 INFO [org.hibernate.cfg.SettingsFactory] - Database -> name : H2 version : 1.3.163 (2011-12-30) major : 1 minor : 3 2018-10-26 20:45:03,373 INFO [org.hibernate.cfg.SettingsFactory] - Driver -> name : H2 JDBC Driver version : 1.3.163 (2011-12-30) major : 1 minor : 3 2018-10-26 20:45:03,374 INFO [org.hibernate.transaction.TransactionFactoryFactory] - Using default transaction strategy (direct JDBC transactions) 2018-10-26 20:45:03,375 INFO [org.hibernate.transaction.TransactionManagerLookupFactory] - No TransactionManagerLookup configured (in JTA environment, use of read-write or transactional second-level cache is not recommended) 2018-10-26 20:45:03,375 INFO [org.hibernate.cfg.SettingsFactory] - Automatic flush during beforeCompletion(): disabled 2018-10-26 20:45:03,375 INFO [org.hibernate.cfg.SettingsFactory] - Automatic session close at end of transaction: disabled 2018-10-26 20:45:03,375 INFO [org.hibernate.cfg.SettingsFactory] - JDBC batch size: 15 2018-10-26 20:45:03,375 INFO [org.hibernate.cfg.SettingsFactory] - JDBC batch updates for versioned data: disabled 2018-10-26 20:45:03,376 INFO [org.hibernate.cfg.SettingsFactory] - Scrollable result sets: enabled 2018-10-26 20:45:03,376 INFO [org.hibernate.cfg.SettingsFactory] - JDBC3 getGeneratedKeys(): enabled 2018-10-26 20:45:03,376 INFO [org.hibernate.cfg.SettingsFactory] - Connection release mode: auto 2018-10-26 20:45:03,376 INFO [org.hibernate.cfg.SettingsFactory] - Default batch fetch size: 1 2018-10-26 20:45:03,377 INFO [org.hibernate.cfg.SettingsFactory] - Generate SQL with comments: disabled 2018-10-26 20:45:03,377 INFO [org.hibernate.cfg.SettingsFactory] - Order SQL updates by primary key: disabled 2018-10-26 20:45:03,377 INFO [org.hibernate.cfg.SettingsFactory] - Order SQL inserts for batching: disabled 2018-10-26 20:45:03,377 INFO [org.hibernate.cfg.SettingsFactory] - Query translator: org.hibernate.hql.ast.ASTQueryTranslatorFactory 2018-10-26 20:45:03,378 INFO [org.hibernate.hql.ast.ASTQueryTranslatorFactory] - Using ASTQueryTranslatorFactory 2018-10-26 20:45:03,378 INFO [org.hibernate.cfg.SettingsFactory] - Query language substitutions: {} 2018-10-26 20:45:03,378 INFO [org.hibernate.cfg.SettingsFactory] - JPA-QL strict compliance: enabled 2018-10-26 20:45:03,378 INFO [org.hibernate.cfg.SettingsFactory] - Second-level cache: enabled 2018-10-26 20:45:03,378 INFO [org.hibernate.cfg.SettingsFactory] - Query cache: disabled 2018-10-26 20:45:03,378 INFO [org.hibernate.cfg.SettingsFactory] - Cache region factory : org.hibernate.cache.impl.NoCachingRegionFactory 2018-10-26 20:45:03,379 INFO [org.hibernate.cfg.SettingsFactory] - Optimize cache for minimal puts: disabled 2018-10-26 20:45:03,379 INFO [org.hibernate.cfg.SettingsFactory] - Structured second-level cache entries: disabled 2018-10-26 20:45:03,381 INFO [org.hibernate.cfg.SettingsFactory] - Echoing all SQL to stdout 2018-10-26 20:45:03,382 INFO [org.hibernate.cfg.SettingsFactory] - Statistics: disabled 2018-10-26 20:45:03,382 INFO [org.hibernate.cfg.SettingsFactory] - Deleted entity synthetic identifier rollback: disabled 2018-10-26 20:45:03,382 INFO [org.hibernate.cfg.SettingsFactory] - Default entity-mode: pojo 2018-10-26 20:45:03,382 INFO [org.hibernate.cfg.SettingsFactory] - Named query checking : enabled 2018-10-26 20:45:03,382 INFO [org.hibernate.cfg.SettingsFactory] - Check Nullability in Core (should be disabled when Bean Validation is on): enabled 2018-10-26 20:45:03,391 INFO [org.hibernate.impl.SessionFactoryImpl] - building session factory 2018-10-26 20:45:03,395 INFO [org.hibernate.type.BasicTypeRegistry] - Type registration [materialized_blob] overrides previous : org.hibernate.type.MaterializedBlobType@295eaa7c 2018-10-26 20:45:03,395 INFO [org.hibernate.type.BasicTypeRegistry] - Type registration [clob] overrides previous : org.hibernate.type.ClobType@3918c187 2018-10-26 20:45:03,395 INFO [org.hibernate.type.BasicTypeRegistry] - Type registration [java.sql.Clob] overrides previous : org.hibernate.type.ClobType@3918c187 2018-10-26 20:45:03,395 INFO [org.hibernate.type.BasicTypeRegistry] - Type registration [characters_clob] overrides previous : org.hibernate.type.PrimitiveCharacterArrayClobType@2c88b9fc 2018-10-26 20:45:03,395 INFO [org.hibernate.type.BasicTypeRegistry] - Type registration [wrapper_materialized_blob] overrides previous : org.hibernate.type.WrappedMaterializedBlobType@64dafeed 2018-10-26 20:45:03,395 INFO [org.hibernate.type.BasicTypeRegistry] - Type registration [wrapper_characters_clob] overrides previous : org.hibernate.type.CharacterArrayClobType@388ba540 2018-10-26 20:45:03,395 INFO [org.hibernate.type.BasicTypeRegistry] - Type registration [blob] overrides previous : org.hibernate.type.BlobType@47605f2f 2018-10-26 20:45:03,395 INFO [org.hibernate.type.BasicTypeRegistry] - Type registration [java.sql.Blob] overrides previous : org.hibernate.type.BlobType@47605f2f 2018-10-26 20:45:03,395 INFO [org.hibernate.type.BasicTypeRegistry] - Type registration [materialized_clob] overrides previous : org.hibernate.type.MaterializedClobType@2ece4966 2018-10-26 20:45:03,546 INFO [org.hibernate.impl.SessionFactoryObjectFactory] - Not binding factory to JNDI, no JNDI name configured 2018-10-26 20:45:03,550 INFO [org.hibernate.tool.hbm2ddl.SchemaUpdate] - Running hbm2ddl schema update 2018-10-26 20:45:03,550 INFO [org.hibernate.tool.hbm2ddl.SchemaUpdate] - fetching database metadata 2018-10-26 20:45:03,551 INFO [org.hibernate.tool.hbm2ddl.SchemaUpdate] - updating schema 2018-10-26 20:45:03,555 INFO [org.hibernate.tool.hbm2ddl.DatabaseMetadata] - table not found: index_task 2018-10-26 20:45:03,556 INFO [org.hibernate.tool.hbm2ddl.DatabaseMetadata] - table not found: index_task 2018-10-26 20:45:03,561 INFO [org.hibernate.tool.hbm2ddl.SchemaUpdate] - schema update complete 2018-10-26 20:45:03,586 INFO [org.springframework.beans.factory.support.DefaultListableBeanFactory] - Pre-instantiating singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@489115ef: defining beans [org.springframework.beans.factory.config.PropertyPlaceholderConfigurer#0,org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor,org.springframework.context.annotation.internalPersistenceAnnotationProcessor,org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor#0,dataSource,jpaVendorAdapter,indexTaskRepository,org.springframework.data.repository.core.support.RepositoryInterfaceAwareBeanPostProcessor#0,entityManagerFactory,transactionManager,org.springframework.aop.config.internalAutoProxyCreator,org.springframework.transaction.annotation.AnnotationTransactionAttributeSource#0,org.springframework.transaction.interceptor.TransactionInterceptor#0,org.springframework.transaction.config.internalTransactionAdvisor,org.springframework.orm.jpa.support.PersistenceAnnotationBeanPostProcessor#0,indexTaskGenerator,indexTaskGeneratorEntryListener,systemMetadataResource,org.springframework.context.annotation.ConfigurationClassPostProcessor.importAwareProcessor]; root of factory hierarchy 2018-10-26 20:45:03,687 WARN [org.dataone.cn.index.util.PerformanceLogger] - Setting up PerformanceLogger: set to enabled? false 2018-10-26 20:45:03,691 INFO [org.dataone.cn.index.generator.filter.HZEventFilter] - HZEvetFilter.constructor - the base url is http://localhost:8983/solr/search_core Oct 26, 2018 8:45:03 PM com.hazelcast.config.ClasspathXmlConfig INFO: Configuring Hazelcast from 'org/dataone/configuration/hazelcast.xml'. Hazelcast Group Config: GroupConfig [name=DataONEBuildTest, password=*******************] Hazelcast Maps: hzObjectPath hzSystemMetadata Oct 26, 2018 8:45:04 PM com.hazelcast.impl.AddressPicker INFO: Interfaces is disabled, trying to pick one address from TCP-IP config addresses: [127.0.0.1] Oct 26, 2018 8:45:04 PM com.hazelcast.impl.AddressPicker WARNING: Picking loopback address [127.0.0.1]; setting 'java.net.preferIPv4Stack' to true. Oct 26, 2018 8:45:04 PM com.hazelcast.impl.AddressPicker INFO: Picked Address[127.0.0.1]:5720, using socket ServerSocket[addr=/0.0.0.0,localport=5720], bind any local is true Oct 26, 2018 8:45:04 PM com.hazelcast.system INFO: [127.0.0.1]:5720 [DataONEBuildTest] Hazelcast Community Edition 2.4.1 (20121213) starting at Address[127.0.0.1]:5720 Oct 26, 2018 8:45:04 PM com.hazelcast.system INFO: [127.0.0.1]:5720 [DataONEBuildTest] Copyright (C) 2008-2012 Hazelcast.com Oct 26, 2018 8:45:04 PM com.hazelcast.impl.LifecycleServiceImpl INFO: [127.0.0.1]:5720 [DataONEBuildTest] Address[127.0.0.1]:5720 is STARTING Oct 26, 2018 8:45:04 PM com.hazelcast.impl.TcpIpJoiner INFO: [127.0.0.1]:5720 [DataONEBuildTest] Members [1] { Member [127.0.0.1]:5720 this } Oct 26, 2018 8:45:04 PM com.hazelcast.impl.LifecycleServiceImpl INFO: [127.0.0.1]:5720 [DataONEBuildTest] Address[127.0.0.1]:5720 is STARTED Hazelcast member hzMember name: _hzInstance_1_DataONEBuildTest Oct 26, 2018 8:45:04 PM com.hazelcast.impl.PartitionManager INFO: [127.0.0.1]:5720 [DataONEBuildTest] Initializing cluster partition table first arrangement... 2018-10-26 20:45:04,579 INFO [org.dataone.cn.index.generator.IndexTaskGeneratorEntryListener] - starting index task generator entry listener... Oct 26, 2018 8:45:04 PM com.hazelcast.config.ClasspathXmlConfig INFO: Configuring Hazelcast from 'org/dataone/configuration/hazelcast.xml'. 2018-10-26 20:45:04,587 INFO [org.dataone.cn.hazelcast.HazelcastClientFactory] - group DataONEBuildTest addresses 127.0.0.1:5720 Oct 26, 2018 8:45:04 PM com.hazelcast.client.LifecycleServiceClientImpl INFO: HazelcastClient is STARTING Oct 26, 2018 8:45:04 PM com.hazelcast.nio.SocketAcceptor INFO: [127.0.0.1]:5720 [DataONEBuildTest] 5720 is accepting socket connection from /127.0.0.1:43329 Oct 26, 2018 8:45:04 PM com.hazelcast.nio.ConnectionManager INFO: [127.0.0.1]:5720 [DataONEBuildTest] 5720 accepted socket connection from /127.0.0.1:43329 Oct 26, 2018 8:45:04 PM com.hazelcast.impl.ClientHandlerService INFO: [127.0.0.1]:5720 [DataONEBuildTest] received auth from Connection [/127.0.0.1:43329 -> null] live=true, client=true, type=CLIENT, successfully authenticated Oct 26, 2018 8:45:04 PM com.hazelcast.client.LifecycleServiceClientImpl INFO: HazelcastClient is CLIENT_CONNECTION_OPENING Oct 26, 2018 8:45:04 PM com.hazelcast.client.LifecycleServiceClientImpl INFO: HazelcastClient is CLIENT_CONNECTION_OPENED Oct 26, 2018 8:45:04 PM com.hazelcast.client.LifecycleServiceClientImpl INFO: HazelcastClient is STARTED 2018-10-26 20:45:04,662 INFO [org.dataone.cn.index.generator.IndexTaskGeneratorEntryListener] - System Metadata size: 0 2018-10-26 20:45:04,663 INFO [org.dataone.cn.index.generator.IndexTaskGeneratorEntryListener] - Object path size:0 2018-10-26 20:45:04,705 INFO [org.dataone.cn.index.generator.IndexTaskGeneratorEntryListener] - ADD EVENT - index task generator - system metadata callback invoked on pid: 42 2018-10-26 20:45:04,706 INFO [org.dataone.cn.index.generator.IndexTaskGeneratorEntryListener] - Processing add event index task for pid: 42 2018-10-26 20:45:04,707 INFO [org.dataone.cn.index.generator.filter.HZEventFilter] - HZEventFilter.fliterOldObject - The modifiction date the object has been less than 300000000 milliseconds old. So the index event for 42 should be granted for indexing by this time filter. But it maybe will be filtered out by other filters. the filter is id:42 2018-10-26 20:45:04,757 WARN [org.dataone.cn.index.generator.filter.HZEventFilter] - HZEventFilter.filter - there was an exception in applying the index event filters for 42. However, this index event still should be granted for indexing for safe. org.apache.solr.client.solrj.SolrServerException: Server refused connection at: http://localhost:8983/solr/search_core at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:567) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:235) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:227) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:135) at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:943) at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:958) at org.dataone.cn.index.generator.filter.HZEventFilter.getSolrReponse(HZEventFilter.java:436) at org.dataone.cn.index.generator.filter.HZEventFilter.filter(HZEventFilter.java:113) at org.dataone.cn.index.generator.IndexTaskGenerator.processSystemMetaDataAdd(IndexTaskGenerator.java:66) at org.dataone.cn.index.generator.IndexTaskGeneratorEntryListener.entryAdded(IndexTaskGeneratorEntryListener.java:114) at com.hazelcast.client.impl.EntryListenerManager.notifyListeners(EntryListenerManager.java:148) at com.hazelcast.client.impl.EntryListenerManager.notifyListeners(EntryListenerManager.java:130) at com.hazelcast.client.impl.ListenerManager.customRun(ListenerManager.java:88) at com.hazelcast.client.ClientRunnable.run(ClientRunnable.java:30) at java.lang.Thread.run(Thread.java:745) Caused by: java.net.ConnectException: Connection refused (Connection refused) at java.net.PlainSocketImpl.socketConnect(Native Method) at java.net.AbstractPlainSocketImpl.doConnect(AbstractPlainSocketImpl.java:350) at java.net.AbstractPlainSocketImpl.connectToAddress(AbstractPlainSocketImpl.java:206) at java.net.AbstractPlainSocketImpl.connect(AbstractPlainSocketImpl.java:188) at java.net.SocksSocketImpl.connect(SocksSocketImpl.java:392) at java.net.Socket.connect(Socket.java:589) at org.apache.http.conn.scheme.PlainSocketFactory.connectSocket(PlainSocketFactory.java:117) at org.apache.http.impl.conn.DefaultClientConnectionOperator.openConnection(DefaultClientConnectionOperator.java:177) at org.apache.http.impl.conn.ManagedClientConnectionImpl.open(ManagedClientConnectionImpl.java:304) at org.apache.http.impl.client.DefaultRequestDirector.tryConnect(DefaultRequestDirector.java:611) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:446) at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:863) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:466) ... 14 more Hibernate: select indextask0_.id as id0_, indextask0_.dateSysMetaModified as dateSysM2_0_, indextask0_.deleted as deleted0_, indextask0_.formatId as formatId0_, indextask0_.nextExecution as nextExec5_0_, indextask0_.objectPath as objectPath0_, indextask0_.pid as pid0_, indextask0_.priority as priority0_, indextask0_.status as status0_, indextask0_.sysMetadata as sysMeta10_0_, indextask0_.taskModifiedDate as taskMod11_0_, indextask0_.tryCount as tryCount0_, indextask0_.version as version0_ from index_task indextask0_ where indextask0_.pid=? and indextask0_.status=? Hibernate: select indextask0_.id as id0_, indextask0_.dateSysMetaModified as dateSysM2_0_, indextask0_.deleted as deleted0_, indextask0_.formatId as formatId0_, indextask0_.nextExecution as nextExec5_0_, indextask0_.objectPath as objectPath0_, indextask0_.pid as pid0_, indextask0_.priority as priority0_, indextask0_.status as status0_, indextask0_.sysMetadata as sysMeta10_0_, indextask0_.taskModifiedDate as taskMod11_0_, indextask0_.tryCount as tryCount0_, indextask0_.version as version0_ from index_task indextask0_ where indextask0_.pid=? and indextask0_.status=? Hibernate: insert into index_task (id, dateSysMetaModified, deleted, formatId, nextExecution, objectPath, pid, priority, status, sysMetadata, taskModifiedDate, tryCount, version) values (null, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) Hibernate: select indextask0_.id as id0_, indextask0_.dateSysMetaModified as dateSysM2_0_, indextask0_.deleted as deleted0_, indextask0_.formatId as formatId0_, indextask0_.nextExecution as nextExec5_0_, indextask0_.objectPath as objectPath0_, indextask0_.pid as pid0_, indextask0_.priority as priority0_, indextask0_.status as status0_, indextask0_.sysMetadata as sysMeta10_0_, indextask0_.taskModifiedDate as taskMod11_0_, indextask0_.tryCount as tryCount0_, indextask0_.version as version0_ from index_task indextask0_ where indextask0_.pid=? 2018-10-26 20:45:06,706 INFO [org.dataone.cn.index.generator.IndexTaskGeneratorEntryListener] - REMOVE EVENT - index task generator - system metadata callback invoked on pid: 42 Hibernate: select indextask0_.id as id0_, indextask0_.dateSysMetaModified as dateSysM2_0_, indextask0_.deleted as deleted0_, indextask0_.formatId as formatId0_, indextask0_.nextExecution as nextExec5_0_, indextask0_.objectPath as objectPath0_, indextask0_.pid as pid0_, indextask0_.priority as priority0_, indextask0_.status as status0_, indextask0_.sysMetadata as sysMeta10_0_, indextask0_.taskModifiedDate as taskMod11_0_, indextask0_.tryCount as tryCount0_, indextask0_.version as version0_ from index_task indextask0_ where indextask0_.pid=? and indextask0_.status=? Hibernate: select indextask0_.id as id0_0_, indextask0_.dateSysMetaModified as dateSysM2_0_0_, indextask0_.deleted as deleted0_0_, indextask0_.formatId as formatId0_0_, indextask0_.nextExecution as nextExec5_0_0_, indextask0_.objectPath as objectPath0_0_, indextask0_.pid as pid0_0_, indextask0_.priority as priority0_0_, indextask0_.status as status0_0_, indextask0_.sysMetadata as sysMeta10_0_0_, indextask0_.taskModifiedDate as taskMod11_0_0_, indextask0_.tryCount as tryCount0_0_, indextask0_.version as version0_0_ from index_task indextask0_ where indextask0_.id=? Hibernate: delete from index_task where id=? and version=? Hibernate: select indextask0_.id as id0_, indextask0_.dateSysMetaModified as dateSysM2_0_, indextask0_.deleted as deleted0_, indextask0_.formatId as formatId0_, indextask0_.nextExecution as nextExec5_0_, indextask0_.objectPath as objectPath0_, indextask0_.pid as pid0_, indextask0_.priority as priority0_, indextask0_.status as status0_, indextask0_.sysMetadata as sysMeta10_0_, indextask0_.taskModifiedDate as taskMod11_0_, indextask0_.tryCount as tryCount0_, indextask0_.version as version0_ from index_task indextask0_ where indextask0_.pid=? and indextask0_.status=? Hibernate: insert into index_task (id, dateSysMetaModified, deleted, formatId, nextExecution, objectPath, pid, priority, status, sysMetadata, taskModifiedDate, tryCount, version) values (null, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) Hibernate: select indextask0_.id as id0_, indextask0_.dateSysMetaModified as dateSysM2_0_, indextask0_.deleted as deleted0_, indextask0_.formatId as formatId0_, indextask0_.nextExecution as nextExec5_0_, indextask0_.objectPath as objectPath0_, indextask0_.pid as pid0_, indextask0_.priority as priority0_, indextask0_.status as status0_, indextask0_.sysMetadata as sysMeta10_0_, indextask0_.taskModifiedDate as taskMod11_0_, indextask0_.tryCount as tryCount0_, indextask0_.version as version0_ from index_task indextask0_ where indextask0_.pid=? 2018-10-26 20:45:10,710 INFO [org.dataone.cn.index.generator.IndexTaskGeneratorEntryListener] - stopping index task generator entry listener... Oct 26, 2018 8:45:10 PM com.hazelcast.impl.LifecycleServiceImpl INFO: [127.0.0.1]:5720 [DataONEBuildTest] Address[127.0.0.1]:5720 is SHUTTING_DOWN Oct 26, 2018 8:45:11 PM com.hazelcast.client.ConnectionManager WARNING: Connection to Connection [0] [localhost/127.0.0.1:5720 -> 127.0.0.1:5720] is lost Oct 26, 2018 8:45:11 PM com.hazelcast.client.LifecycleServiceClientImpl INFO: HazelcastClient is CLIENT_CONNECTION_LOST Oct 26, 2018 8:45:11 PM com.hazelcast.nio.Connection INFO: [127.0.0.1]:5720 [DataONEBuildTest] Connection [Address[127.0.0.1]:43329] lost. Reason: Explicit close Oct 26, 2018 8:45:11 PM com.hazelcast.client.ConnectionManager WARNING: got an exception on getConnection:Connection reset java.net.SocketException: Connection reset at java.net.SocketInputStream.read(SocketInputStream.java:209) at java.net.SocketInputStream.read(SocketInputStream.java:141) at java.io.BufferedInputStream.fill(BufferedInputStream.java:246) at java.io.BufferedInputStream.read1(BufferedInputStream.java:286) at java.io.BufferedInputStream.read(BufferedInputStream.java:345) at java.io.DataInputStream.readFully(DataInputStream.java:195) at java.io.DataInputStream.readFully(DataInputStream.java:169) at com.hazelcast.client.PacketReader.readPacket(PacketReader.java:32) at com.hazelcast.client.DefaultClientBinder.writeAndRead(DefaultClientBinder.java:74) at com.hazelcast.client.DefaultClientBinder.auth(DefaultClientBinder.java:61) at com.hazelcast.client.DefaultClientBinder.bind(DefaultClientBinder.java:44) at com.hazelcast.client.ConnectionManager.bindConnection(ConnectionManager.java:225) at com.hazelcast.client.ConnectionManager.lookForLiveConnection(ConnectionManager.java:139) at com.hazelcast.client.ConnectionManager.lookForLiveConnection(ConnectionManager.java:115) at com.hazelcast.client.OutRunnable$1.run(OutRunnable.java:176) at com.hazelcast.client.HazelcastClient$1.call(HazelcastClient.java:344) at com.hazelcast.client.HazelcastClient$1.call(HazelcastClient.java:342) at java.util.concurrent.FutureTask.run(FutureTask.java:266) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617) at java.lang.Thread.run(Thread.java:745) Oct 26, 2018 8:45:11 PM com.hazelcast.client.ConnectionManager INFO: Unable to get alive cluster connection, try in 4,983 ms later, attempt 1 of 1. Oct 26, 2018 8:45:11 PM com.hazelcast.initializer INFO: [127.0.0.1]:5720 [DataONEBuildTest] Destroying node initializer. Oct 26, 2018 8:45:11 PM com.hazelcast.impl.Node INFO: [127.0.0.1]:5720 [DataONEBuildTest] Hazelcast Shutdown is completed in 630 ms. Oct 26, 2018 8:45:11 PM com.hazelcast.impl.LifecycleServiceImpl INFO: [127.0.0.1]:5720 [DataONEBuildTest] Address[127.0.0.1]:5720 is SHUTDOWN Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 9.184 sec Running org.dataone.cn.index.test.IndexTaskGeneratorTest 2018-10-26 20:45:11,380 INFO [org.springframework.test.context.TestContextManager] - @TestExecutionListeners is not present for class [class org.dataone.cn.index.test.IndexTaskGeneratorTest]: using defaults. Hibernate: select indextask0_.id as id0_, indextask0_.dateSysMetaModified as dateSysM2_0_, indextask0_.deleted as deleted0_, indextask0_.formatId as formatId0_, indextask0_.nextExecution as nextExec5_0_, indextask0_.objectPath as objectPath0_, indextask0_.pid as pid0_, indextask0_.priority as priority0_, indextask0_.status as status0_, indextask0_.sysMetadata as sysMeta10_0_, indextask0_.taskModifiedDate as taskMod11_0_, indextask0_.tryCount as tryCount0_, indextask0_.version as version0_ from index_task indextask0_ Hibernate: insert into index_task (id, dateSysMetaModified, deleted, formatId, nextExecution, objectPath, pid, priority, status, sysMetadata, taskModifiedDate, tryCount, version) values (null, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) Hibernate: select indextask0_.id as id0_, indextask0_.dateSysMetaModified as dateSysM2_0_, indextask0_.deleted as deleted0_, indextask0_.formatId as formatId0_, indextask0_.nextExecution as nextExec5_0_, indextask0_.objectPath as objectPath0_, indextask0_.pid as pid0_, indextask0_.priority as priority0_, indextask0_.status as status0_, indextask0_.sysMetadata as sysMeta10_0_, indextask0_.taskModifiedDate as taskMod11_0_, indextask0_.tryCount as tryCount0_, indextask0_.version as version0_ from index_task indextask0_ Hibernate: select indextask0_.id as id0_0_, indextask0_.dateSysMetaModified as dateSysM2_0_0_, indextask0_.deleted as deleted0_0_, indextask0_.formatId as formatId0_0_, indextask0_.nextExecution as nextExec5_0_0_, indextask0_.objectPath as objectPath0_0_, indextask0_.pid as pid0_0_, indextask0_.priority as priority0_0_, indextask0_.status as status0_0_, indextask0_.sysMetadata as sysMeta10_0_0_, indextask0_.taskModifiedDate as taskMod11_0_0_, indextask0_.tryCount as tryCount0_0_, indextask0_.version as version0_0_ from index_task indextask0_ where indextask0_.id=? Hibernate: delete from index_task where id=? and version=? Hibernate: select indextask0_.id as id0_, indextask0_.dateSysMetaModified as dateSysM2_0_, indextask0_.deleted as deleted0_, indextask0_.formatId as formatId0_, indextask0_.nextExecution as nextExec5_0_, indextask0_.objectPath as objectPath0_, indextask0_.pid as pid0_, indextask0_.priority as priority0_, indextask0_.status as status0_, indextask0_.sysMetadata as sysMeta10_0_, indextask0_.taskModifiedDate as taskMod11_0_, indextask0_.tryCount as tryCount0_, indextask0_.version as version0_ from index_task indextask0_ 2018-10-26 20:45:11,396 INFO [org.dataone.cn.index.generator.filter.HZEventFilter] - HZEventFilter.fliterOldObject - The modifiction date the object has been less than 300000000 milliseconds old. So the index event for gen-test-duplicate-b0823255-3cc5-4da6-94a9-3ef826c3bb4d should be granted for indexing by this time filter. But it maybe will be filtered out by other filters. the filter is id:gen\-test\-duplicate\-b0823255\-3cc5\-4da6\-94a9\-3ef826c3bb4d 2018-10-26 20:45:11,397 WARN [org.dataone.cn.index.generator.filter.HZEventFilter] - HZEventFilter.filter - there was an exception in applying the index event filters for gen-test-duplicate-b0823255-3cc5-4da6-94a9-3ef826c3bb4d. However, this index event still should be granted for indexing for safe. java.lang.IllegalStateException: Connection pool shut down at org.apache.http.util.Asserts.check(Asserts.java:34) at org.apache.http.pool.AbstractConnPool.lease(AbstractConnPool.java:184) at org.apache.http.pool.AbstractConnPool.lease(AbstractConnPool.java:217) at org.apache.http.impl.conn.PoolingClientConnectionManager.requestConnection(PoolingClientConnectionManager.java:184) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:415) at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:863) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:466) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:235) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:227) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:135) at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:943) at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:958) at org.dataone.cn.index.generator.filter.HZEventFilter.getSolrReponse(HZEventFilter.java:436) at org.dataone.cn.index.generator.filter.HZEventFilter.filter(HZEventFilter.java:113) at org.dataone.cn.index.generator.IndexTaskGenerator.processSystemMetaDataAdd(IndexTaskGenerator.java:66) at org.dataone.cn.index.test.IndexTaskGeneratorTest.testDuplicateTask(IndexTaskGeneratorTest.java:70) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20) at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:74) at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:83) at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:72) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:231) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222) at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61) at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:71) at org.junit.runners.ParentRunner.run(ParentRunner.java:300) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:174) at org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:53) at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:123) at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:104) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:164) at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:110) at org.apache.maven.surefire.booter.SurefireStarter.invokeProvider(SurefireStarter.java:175) at org.apache.maven.surefire.booter.SurefireStarter.runSuitesInProcessWhenForked(SurefireStarter.java:107) at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:68) Hibernate: select indextask0_.id as id0_, indextask0_.dateSysMetaModified as dateSysM2_0_, indextask0_.deleted as deleted0_, indextask0_.formatId as formatId0_, indextask0_.nextExecution as nextExec5_0_, indextask0_.objectPath as objectPath0_, indextask0_.pid as pid0_, indextask0_.priority as priority0_, indextask0_.status as status0_, indextask0_.sysMetadata as sysMeta10_0_, indextask0_.taskModifiedDate as taskMod11_0_, indextask0_.tryCount as tryCount0_, indextask0_.version as version0_ from index_task indextask0_ where indextask0_.pid=? and indextask0_.status=? Hibernate: select indextask0_.id as id0_, indextask0_.dateSysMetaModified as dateSysM2_0_, indextask0_.deleted as deleted0_, indextask0_.formatId as formatId0_, indextask0_.nextExecution as nextExec5_0_, indextask0_.objectPath as objectPath0_, indextask0_.pid as pid0_, indextask0_.priority as priority0_, indextask0_.status as status0_, indextask0_.sysMetadata as sysMeta10_0_, indextask0_.taskModifiedDate as taskMod11_0_, indextask0_.tryCount as tryCount0_, indextask0_.version as version0_ from index_task indextask0_ where indextask0_.pid=? and indextask0_.status=? Hibernate: insert into index_task (id, dateSysMetaModified, deleted, formatId, nextExecution, objectPath, pid, priority, status, sysMetadata, taskModifiedDate, tryCount, version) values (null, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) 2018-10-26 20:45:11,406 INFO [org.dataone.cn.index.test.IndexTaskGeneratorTest] - ***Dupe test, first id: 4 2018-10-26 20:45:11,406 INFO [org.dataone.cn.index.generator.filter.HZEventFilter] - HZEventFilter.fliterOldObject - The modifiction date the object has been less than 300000000 milliseconds old. So the index event for gen-test-duplicate-b0823255-3cc5-4da6-94a9-3ef826c3bb4d should be granted for indexing by this time filter. But it maybe will be filtered out by other filters. the filter is id:gen\-test\-duplicate\-b0823255\-3cc5\-4da6\-94a9\-3ef826c3bb4d 2018-10-26 20:45:11,407 WARN [org.dataone.cn.index.generator.filter.HZEventFilter] - HZEventFilter.filter - there was an exception in applying the index event filters for gen-test-duplicate-b0823255-3cc5-4da6-94a9-3ef826c3bb4d. However, this index event still should be granted for indexing for safe. java.lang.IllegalStateException: Connection pool shut down at org.apache.http.util.Asserts.check(Asserts.java:34) at org.apache.http.pool.AbstractConnPool.lease(AbstractConnPool.java:184) at org.apache.http.pool.AbstractConnPool.lease(AbstractConnPool.java:217) at org.apache.http.impl.conn.PoolingClientConnectionManager.requestConnection(PoolingClientConnectionManager.java:184) at org.apache.http.impl.client.DefaultRequestDirector.execute(DefaultRequestDirector.java:415) at org.apache.http.impl.client.AbstractHttpClient.doExecute(AbstractHttpClient.java:863) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:82) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:106) at org.apache.http.impl.client.CloseableHttpClient.execute(CloseableHttpClient.java:57) at org.apache.solr.client.solrj.impl.HttpSolrClient.executeMethod(HttpSolrClient.java:466) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:235) at org.apache.solr.client.solrj.impl.HttpSolrClient.request(HttpSolrClient.java:227) at org.apache.solr.client.solrj.SolrRequest.process(SolrRequest.java:135) at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:943) at org.apache.solr.client.solrj.SolrClient.query(SolrClient.java:958) at org.dataone.cn.index.generator.filter.HZEventFilter.getSolrReponse(HZEventFilter.java:436) at org.dataone.cn.index.generator.filter.HZEventFilter.filter(HZEventFilter.java:113) at org.dataone.cn.index.generator.IndexTaskGenerator.processSystemMetaDataAdd(IndexTaskGenerator.java:66) at org.dataone.cn.index.test.IndexTaskGeneratorTest.testDuplicateTask(IndexTaskGeneratorTest.java:73) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:45) at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:15) at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:42) at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:20) at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:74) at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:83) at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:72) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:231) at org.junit.runners.BlockJUnit4ClassRunner.runChild(BlockJUnit4ClassRunner.java:47) at org.junit.runners.ParentRunner$3.run(ParentRunner.java:231) at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:60) at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:229) at org.junit.runners.ParentRunner.access$000(ParentRunner.java:50) at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:222) at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61) at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:71) at org.junit.runners.ParentRunner.run(ParentRunner.java:300) at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:174) at org.apache.maven.surefire.junit4.JUnit4TestSet.execute(JUnit4TestSet.java:53) at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:123) at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:104) at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method) at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62) at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43) at java.lang.reflect.Method.invoke(Method.java:498) at org.apache.maven.surefire.util.ReflectionUtils.invokeMethodWithArray(ReflectionUtils.java:164) at org.apache.maven.surefire.booter.ProviderFactory$ProviderProxy.invoke(ProviderFactory.java:110) at org.apache.maven.surefire.booter.SurefireStarter.invokeProvider(SurefireStarter.java:175) at org.apache.maven.surefire.booter.SurefireStarter.runSuitesInProcessWhenForked(SurefireStarter.java:107) at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:68) Hibernate: select indextask0_.id as id0_, indextask0_.dateSysMetaModified as dateSysM2_0_, indextask0_.deleted as deleted0_, indextask0_.formatId as formatId0_, indextask0_.nextExecution as nextExec5_0_, indextask0_.objectPath as objectPath0_, indextask0_.pid as pid0_, indextask0_.priority as priority0_, indextask0_.status as status0_, indextask0_.sysMetadata as sysMeta10_0_, indextask0_.taskModifiedDate as taskMod11_0_, indextask0_.tryCount as tryCount0_, indextask0_.version as version0_ from index_task indextask0_ where indextask0_.pid=? and indextask0_.status=? Hibernate: select indextask0_.id as id0_0_, indextask0_.dateSysMetaModified as dateSysM2_0_0_, indextask0_.deleted as deleted0_0_, indextask0_.formatId as formatId0_0_, indextask0_.nextExecution as nextExec5_0_0_, indextask0_.objectPath as objectPath0_0_, indextask0_.pid as pid0_0_, indextask0_.priority as priority0_0_, indextask0_.status as status0_0_, indextask0_.sysMetadata as sysMeta10_0_0_, indextask0_.taskModifiedDate as taskMod11_0_0_, indextask0_.tryCount as tryCount0_0_, indextask0_.version as version0_0_ from index_task indextask0_ where indextask0_.id=? Hibernate: delete from index_task where id=? and version=? Hibernate: select indextask0_.id as id0_, indextask0_.dateSysMetaModified as dateSysM2_0_, indextask0_.deleted as deleted0_, indextask0_.formatId as formatId0_, indextask0_.nextExecution as nextExec5_0_, indextask0_.objectPath as objectPath0_, indextask0_.pid as pid0_, indextask0_.priority as priority0_, indextask0_.status as status0_, indextask0_.sysMetadata as sysMeta10_0_, indextask0_.taskModifiedDate as taskMod11_0_, indextask0_.tryCount as tryCount0_, indextask0_.version as version0_ from index_task indextask0_ where indextask0_.pid=? and indextask0_.status=? Hibernate: insert into index_task (id, dateSysMetaModified, deleted, formatId, nextExecution, objectPath, pid, priority, status, sysMetadata, taskModifiedDate, tryCount, version) values (null, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?) 2018-10-26 20:45:11,416 INFO [org.dataone.cn.index.test.IndexTaskGeneratorTest] - ***Dupe test, second id: 5 Hibernate: select count(*) as col_0_0_ from index_task indextask0_ where indextask0_.id=? and 1=1 limit ? Hibernate: select indextask0_.id as id0_0_, indextask0_.dateSysMetaModified as dateSysM2_0_0_, indextask0_.deleted as deleted0_0_, indextask0_.formatId as formatId0_0_, indextask0_.nextExecution as nextExec5_0_0_, indextask0_.objectPath as objectPath0_0_, indextask0_.pid as pid0_0_, indextask0_.priority as priority0_0_, indextask0_.status as status0_0_, indextask0_.sysMetadata as sysMeta10_0_0_, indextask0_.taskModifiedDate as taskMod11_0_0_, indextask0_.tryCount as tryCount0_0_, indextask0_.version as version0_0_ from index_task indextask0_ where indextask0_.id=? Hibernate: select count(*) as col_0_0_ from index_task indextask0_ where indextask0_.id=? and 1=1 limit ? Hibernate: select indextask0_.id as id0_0_, indextask0_.dateSysMetaModified as dateSysM2_0_0_, indextask0_.deleted as deleted0_0_, indextask0_.formatId as formatId0_0_, indextask0_.nextExecution as nextExec5_0_0_, indextask0_.objectPath as objectPath0_0_, indextask0_.pid as pid0_0_, indextask0_.priority as priority0_0_, indextask0_.status as status0_0_, indextask0_.sysMetadata as sysMeta10_0_0_, indextask0_.taskModifiedDate as taskMod11_0_0_, indextask0_.tryCount as tryCount0_0_, indextask0_.version as version0_0_ from index_task indextask0_ where indextask0_.id=? Tests run: 3, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.035 sec 2018-10-26 20:45:11,429 INFO [org.springframework.context.support.GenericApplicationContext] - Closing org.springframework.context.support.GenericApplicationContext@5e57643e: startup date [Fri Oct 26 20:45:02 UTC 2018]; root of context hierarchy 2018-10-26 20:45:11,430 INFO [org.springframework.beans.factory.support.DefaultListableBeanFactory] - Destroying singletons in org.springframework.beans.factory.support.DefaultListableBeanFactory@489115ef: defining beans [org.springframework.beans.factory.config.PropertyPlaceholderConfigurer#0,org.springframework.context.annotation.internalConfigurationAnnotationProcessor,org.springframework.context.annotation.internalAutowiredAnnotationProcessor,org.springframework.context.annotation.internalRequiredAnnotationProcessor,org.springframework.context.annotation.internalCommonAnnotationProcessor,org.springframework.context.annotation.internalPersistenceAnnotationProcessor,org.springframework.beans.factory.annotation.AutowiredAnnotationBeanPostProcessor#0,dataSource,jpaVendorAdapter,indexTaskRepository,org.springframework.data.repository.core.support.RepositoryInterfaceAwareBeanPostProcessor#0,entityManagerFactory,transactionManager,org.springframework.aop.config.internalAutoProxyCreator,org.springframework.transaction.annotation.AnnotationTransactionAttributeSource#0,org.springframework.transaction.interceptor.TransactionInterceptor#0,org.springframework.transaction.config.internalTransactionAdvisor,org.springframework.orm.jpa.support.PersistenceAnnotationBeanPostProcessor#0,indexTaskGenerator,indexTaskGeneratorEntryListener,systemMetadataResource,org.springframework.context.annotation.ConfigurationClassPostProcessor.importAwareProcessor]; root of factory hierarchy 2018-10-26 20:45:11,431 INFO [org.springframework.orm.jpa.LocalContainerEntityManagerFactoryBean] - Closing JPA EntityManagerFactory for persistence unit 'default' 2018-10-26 20:45:11,431 INFO [org.hibernate.impl.SessionFactoryImpl] - closing Results : Tests run: 4, Failures: 0, Errors: 0, Skipped: 0 [JENKINS] Recording test results [WARNING] Attempt to (de-)serialize anonymous class hudson.maven.reporters.SurefireArchiver$2; see: https://jenkins.io/redirect/serialization-of-anonymous-classes/ [WARNING] Attempt to (de-)serialize anonymous class hudson.maven.reporters.BuildInfoRecorder$1; see: https://jenkins.io/redirect/serialization-of-anonymous-classes/ [INFO] [INFO] --- maven-jar-plugin:2.2:jar (default-jar) @ d1_cn_index_generator --- [INFO] Building jar: /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/d1_cn_index_generator-2.3.3.jar [INFO] [INFO] --- maven-shade-plugin:1.7.1:shade (default) @ d1_cn_index_generator --- [INFO] Including org.dataone:d1_cn_index_common:jar:2.3.2 in the shaded jar. [INFO] Including org.dataone:d1_common_java:jar:2.3.0 in the shaded jar. [INFO] Including javax.mail:mail:jar:1.4.1 in the shaded jar. [INFO] Including javax.activation:activation:jar:1.1 in the shaded jar. [INFO] Including javax.xml.bind:jaxb-api:jar:2.2.3 in the shaded jar. [INFO] Including javax.xml.stream:stax-api:jar:1.0-2 in the shaded jar. [INFO] Including joda-time:joda-time:jar:2.1 in the shaded jar. [INFO] Including log4j:log4j:jar:1.2.17 in the shaded jar. [INFO] Including org.apache.maven.plugins:maven-compiler-plugin:maven-plugin:2.3.1 in the shaded jar. [INFO] Including org.codehaus.plexus:plexus-container-default:jar:1.0-alpha-9-stable-1 in the shaded jar. [INFO] Including classworlds:classworlds:jar:1.1-alpha-2 in the shaded jar. [INFO] Including org.apache.maven:maven-plugin-api:jar:2.0.6 in the shaded jar. [INFO] Including org.apache.maven:maven-artifact:jar:2.0.6 in the shaded jar. [INFO] Including org.apache.maven:maven-core:jar:2.0.6 in the shaded jar. [INFO] Including org.apache.maven:maven-settings:jar:2.0.6 in the shaded jar. [INFO] Including org.apache.maven.wagon:wagon-file:jar:1.0-beta-2 in the shaded jar. [INFO] Including org.apache.maven:maven-plugin-parameter-documenter:jar:2.0.6 in the shaded jar. [INFO] Including org.apache.maven.wagon:wagon-http-lightweight:jar:1.0-beta-2 in the shaded jar. [INFO] Including org.apache.maven.wagon:wagon-http-shared:jar:1.0-beta-2 in the shaded jar. [INFO] Including jtidy:jtidy:jar:4aug2000r7-dev in the shaded jar. [INFO] Including xml-apis:xml-apis:jar:1.0.b2 in the shaded jar. [INFO] Including org.apache.maven.reporting:maven-reporting-api:jar:2.0.6 in the shaded jar. [INFO] Including org.apache.maven.doxia:doxia-sink-api:jar:1.0-alpha-7 in the shaded jar. [INFO] Including org.apache.maven:maven-profile:jar:2.0.6 in the shaded jar. [INFO] Including org.apache.maven.wagon:wagon-provider-api:jar:1.0-beta-2 in the shaded jar. [INFO] Including org.apache.maven:maven-repository-metadata:jar:2.0.6 in the shaded jar. [INFO] Including org.apache.maven:maven-error-diagnostics:jar:2.0.6 in the shaded jar. [INFO] Including commons-cli:commons-cli:jar:1.0 in the shaded jar. [INFO] Including org.apache.maven.wagon:wagon-ssh-external:jar:1.0-beta-2 in the shaded jar. [INFO] Including org.apache.maven.wagon:wagon-ssh-common:jar:1.0-beta-2 in the shaded jar. [INFO] Including org.apache.maven:maven-plugin-descriptor:jar:2.0.6 in the shaded jar. [INFO] Including org.codehaus.plexus:plexus-interactivity-api:jar:1.0-alpha-4 in the shaded jar. [INFO] Including org.apache.maven:maven-artifact-manager:jar:2.0.6 in the shaded jar. [INFO] Including org.apache.maven:maven-monitor:jar:2.0.6 in the shaded jar. [INFO] Including org.apache.maven.wagon:wagon-ssh:jar:1.0-beta-2 in the shaded jar. [INFO] Including com.jcraft:jsch:jar:0.1.27 in the shaded jar. [INFO] Including org.codehaus.plexus:plexus-utils:jar:2.0.5 in the shaded jar. [INFO] Including org.codehaus.plexus:plexus-compiler-api:jar:1.8 in the shaded jar. [INFO] Including org.apache.maven:maven-toolchain:jar:1.0 in the shaded jar. [INFO] Including org.codehaus.plexus:plexus-compiler-manager:jar:1.8 in the shaded jar. [INFO] Including org.codehaus.plexus:plexus-compiler-javac:jar:1.8 in the shaded jar. [INFO] Including org.apache.maven.plugins:maven-jar-plugin:maven-plugin:2.3.1 in the shaded jar. [INFO] Including org.apache.maven:maven-project:jar:2.0.6 in the shaded jar. [INFO] Including org.apache.maven:maven-plugin-registry:jar:2.0.6 in the shaded jar. [INFO] Including org.apache.maven:maven-model:jar:2.0.6 in the shaded jar. [INFO] Including org.apache.maven:maven-archiver:jar:2.4.1 in the shaded jar. [INFO] Including org.codehaus.plexus:plexus-interpolation:jar:1.13 in the shaded jar. [INFO] Including org.codehaus.plexus:plexus-archiver:jar:1.0 in the shaded jar. [INFO] Including org.codehaus.plexus:plexus-io:jar:1.0 in the shaded jar. [INFO] Including org.apache.maven.plugins:maven-clean-plugin:maven-plugin:2.4.1 in the shaded jar. [INFO] Including commons-fileupload:commons-fileupload:jar:1.3.1 in the shaded jar. [INFO] Including org.apache.httpcomponents:httpmime:jar:4.3.3 in the shaded jar. [INFO] Including org.apache.httpcomponents:httpclient:jar:4.3.3 in the shaded jar. [INFO] Including commons-codec:commons-codec:jar:1.6 in the shaded jar. [INFO] Including org.apache.commons:commons-collections4:jar:4.0 in the shaded jar. [INFO] Including org.apache.commons:commons-lang3:jar:3.3.2 in the shaded jar. [INFO] Including commons-configuration:commons-configuration:jar:1.7 in the shaded jar. [INFO] Including commons-collections:commons-collections:jar:3.2.1 in the shaded jar. [INFO] Including commons-digester:commons-digester:jar:1.8.1 in the shaded jar. [INFO] Including commons-beanutils:commons-beanutils:jar:1.9.2 in the shaded jar. [INFO] Including org.dataone:d1_cn_common:jar:2.3.0 in the shaded jar. [INFO] Including commons-logging:commons-logging:jar:1.1.1 in the shaded jar. [INFO] Including com.hazelcast:hazelcast-client:jar:2.4.1 in the shaded jar. [INFO] Including org.apache.solr:solr-solrj:jar:5.2.1 in the shaded jar. [INFO] Including org.apache.httpcomponents:httpcore:jar:4.4.1 in the shaded jar. [INFO] Including org.apache.zookeeper:zookeeper:jar:3.4.6 in the shaded jar. [INFO] Including org.codehaus.woodstox:stax2-api:jar:3.1.4 in the shaded jar. [INFO] Including org.codehaus.woodstox:woodstox-core-asl:jar:4.4.1 in the shaded jar. [INFO] Including org.noggit:noggit:jar:0.6 in the shaded jar. [INFO] Including org.apache.commons:commons-pool2:jar:2.4.2 in the shaded jar. [INFO] Including commons-daemon:commons-daemon:jar:1.0.1 in the shaded jar. [INFO] Including com.hazelcast:hazelcast:jar:2.4.1 in the shaded jar. [INFO] Including com.hazelcast:hazelcast-spring:jar:2.4.1 in the shaded jar. [INFO] Including org.jibx:jibx-run:jar:1.2.4.5 in the shaded jar. [INFO] Including xpp3:xpp3:jar:1.1.3.4.O in the shaded jar. [INFO] Including org.springframework:spring-core:jar:3.1.4.RELEASE in the shaded jar. [INFO] Including org.springframework:spring-asm:jar:3.1.4.RELEASE in the shaded jar. [INFO] Including org.springframework:spring-beans:jar:3.1.4.RELEASE in the shaded jar. [INFO] Including org.springframework:spring-context:jar:3.1.4.RELEASE in the shaded jar. [INFO] Including org.springframework:spring-expression:jar:3.1.4.RELEASE in the shaded jar. [INFO] Including org.springframework:spring-aop:jar:3.1.4.RELEASE in the shaded jar. [INFO] Including aopalliance:aopalliance:jar:1.0 in the shaded jar. [INFO] Including org.springframework:spring-context-support:jar:3.1.4.RELEASE in the shaded jar. [INFO] Including org.springframework:spring-tx:jar:3.1.4.RELEASE in the shaded jar. [INFO] Including org.springframework:spring-orm:jar:3.1.4.RELEASE in the shaded jar. [INFO] Including org.springframework:spring-jdbc:jar:3.1.4.RELEASE in the shaded jar. [INFO] Including org.springframework:spring-test:jar:3.1.4.RELEASE in the shaded jar. [INFO] Including org.springframework.data:spring-data-jpa:jar:1.4.5.RELEASE in the shaded jar. [INFO] Including org.aspectj:aspectjrt:jar:1.7.2 in the shaded jar. [INFO] Including org.slf4j:jcl-over-slf4j:jar:1.7.1 in the shaded jar. [INFO] Including org.springframework.data:spring-data-commons:jar:1.6.5.RELEASE in the shaded jar. [INFO] Including org.hibernate:hibernate-entitymanager:jar:3.6.10.Final in the shaded jar. [INFO] Including org.hibernate:hibernate-core:jar:3.6.10.Final in the shaded jar. [INFO] Including antlr:antlr:jar:2.7.6 in the shaded jar. [INFO] Including dom4j:dom4j:jar:1.6.1 in the shaded jar. [INFO] Including org.hibernate:hibernate-commons-annotations:jar:3.2.0.Final in the shaded jar. [INFO] Including javax.transaction:jta:jar:1.1 in the shaded jar. [INFO] Including javassist:javassist:jar:3.12.0.GA in the shaded jar. [INFO] Including org.hibernate.javax.persistence:hibernate-jpa-2.0-api:jar:1.0.1.Final in the shaded jar. [INFO] Including cglib:cglib:jar:3.1 in the shaded jar. [INFO] Including org.ow2.asm:asm:jar:4.2 in the shaded jar. [INFO] Including commons-dbcp:commons-dbcp:jar:1.2.2 in the shaded jar. [INFO] Including commons-pool:commons-pool:jar:1.3 in the shaded jar. [INFO] Including postgresql:postgresql:jar:8.4-702.jdbc4 in the shaded jar. [INFO] Including commons-io:commons-io:jar:2.0.1 in the shaded jar. [INFO] Including commons-lang:commons-lang:jar:2.6 in the shaded jar. [INFO] Including org.slf4j:slf4j-api:jar:1.7.5 in the shaded jar. [INFO] Including org.slf4j:slf4j-log4j12:jar:1.7.5 in the shaded jar. [WARNING] We have a duplicate org/w3c/dom/Attr.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/w3c/dom/CDATASection.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/w3c/dom/CharacterData.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/w3c/dom/Comment.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/w3c/dom/Document.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/w3c/dom/DocumentFragment.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/w3c/dom/DocumentType.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/w3c/dom/DOMException.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/w3c/dom/DOMImplementation.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/w3c/dom/Element.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/w3c/dom/Entity.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/w3c/dom/EntityReference.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/w3c/dom/NamedNodeMap.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/w3c/dom/Node.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/w3c/dom/NodeList.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/w3c/dom/Notation.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/w3c/dom/ProcessingInstruction.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/w3c/dom/Text.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/xml/sax/AttributeList.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/xml/sax/Attributes.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/xml/sax/ContentHandler.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/xml/sax/DocumentHandler.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/xml/sax/DTDHandler.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/xml/sax/EntityResolver.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/xml/sax/ErrorHandler.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/xml/sax/HandlerBase.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/xml/sax/InputSource.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/xml/sax/Locator.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/xml/sax/Parser.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/xml/sax/SAXException.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/xml/sax/SAXNotRecognizedException.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/xml/sax/SAXNotSupportedException.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/xml/sax/SAXParseException.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/xml/sax/XMLFilter.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/xml/sax/XMLReader.class in /var/lib/jenkins/.m2/repository/xml-apis/xml-apis/1.0.b2/xml-apis-1.0.b2.jar [WARNING] We have a duplicate org/apache/commons/logging/impl/NoOpLog.class in /var/lib/jenkins/.m2/repository/org/slf4j/jcl-over-slf4j/1.7.1/jcl-over-slf4j-1.7.1.jar [WARNING] We have a duplicate org/apache/commons/logging/impl/SimpleLog$1.class in /var/lib/jenkins/.m2/repository/org/slf4j/jcl-over-slf4j/1.7.1/jcl-over-slf4j-1.7.1.jar [WARNING] We have a duplicate org/apache/commons/logging/impl/SimpleLog.class in /var/lib/jenkins/.m2/repository/org/slf4j/jcl-over-slf4j/1.7.1/jcl-over-slf4j-1.7.1.jar [WARNING] We have a duplicate org/apache/commons/logging/Log.class in /var/lib/jenkins/.m2/repository/org/slf4j/jcl-over-slf4j/1.7.1/jcl-over-slf4j-1.7.1.jar [WARNING] We have a duplicate org/apache/commons/logging/LogConfigurationException.class in /var/lib/jenkins/.m2/repository/org/slf4j/jcl-over-slf4j/1.7.1/jcl-over-slf4j-1.7.1.jar [WARNING] We have a duplicate org/apache/commons/logging/LogFactory.class in /var/lib/jenkins/.m2/repository/org/slf4j/jcl-over-slf4j/1.7.1/jcl-over-slf4j-1.7.1.jar [INFO] [INFO] --- maven-install-plugin:2.3:install (default-install) @ d1_cn_index_generator --- [INFO] Installing /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/d1_cn_index_generator-2.3.3.jar to /var/lib/jenkins/.m2/repository/org/dataone/d1_cn_index_generator/2.3.3/d1_cn_index_generator-2.3.3.jar [INFO] Installing /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/pom.xml to /var/lib/jenkins/.m2/repository/org/dataone/d1_cn_index_generator/2.3.3/d1_cn_index_generator-2.3.3.pom [INFO] [INFO] --- buildnumber-maven-plugin:1.4:create (default) @ d1_cn_index_generator --- [INFO] Executing: /bin/sh -c cd '/var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace' && 'svn' '--non-interactive' 'info' [INFO] Working directory: /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace [INFO] Storing buildNumber: 19418 at timestamp: 1540586717517 [INFO] Executing: /bin/sh -c cd '/var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace' && 'svn' '--non-interactive' 'info' [INFO] Working directory: /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace [INFO] Storing buildScmBranch: tags/D1_CN_INDEX_GENERATOR_v2.3.3 [WARNING] Failed to getClass for org.apache.maven.plugin.javadoc.JavadocReport [INFO] [INFO] --- maven-javadoc-plugin:2.10.4:javadoc (default-cli) @ d1_cn_index_generator --- [INFO] Loading source files for package org.dataone.cn.index.generator... Loading source files for package org.dataone.cn.index.generator.filter... Constructing Javadoc information... Standard Doclet version 1.8.0_111 Building tree for all the packages and classes... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/org/dataone/cn/index/generator/IndexTaskGenerator.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/org/dataone/cn/index/generator/IndexTaskGeneratorDaemon.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/org/dataone/cn/index/generator/IndexTaskGeneratorEntryListener.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/org/dataone/cn/index/generator/filter/HZEventFilter.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/overview-frame.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/org/dataone/cn/index/generator/package-frame.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/org/dataone/cn/index/generator/package-summary.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/org/dataone/cn/index/generator/package-tree.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/org/dataone/cn/index/generator/filter/package-frame.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/org/dataone/cn/index/generator/filter/package-summary.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/org/dataone/cn/index/generator/filter/package-tree.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/constant-values.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/org/dataone/cn/index/generator/class-use/IndexTaskGeneratorDaemon.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/org/dataone/cn/index/generator/class-use/IndexTaskGeneratorEntryListener.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/org/dataone/cn/index/generator/class-use/IndexTaskGenerator.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/org/dataone/cn/index/generator/filter/class-use/HZEventFilter.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/org/dataone/cn/index/generator/package-use.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/org/dataone/cn/index/generator/filter/package-use.html... Building index for all the packages and classes... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/overview-tree.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/index-all.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/deprecated-list.html... Building index for all classes... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/allclasses-frame.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/allclasses-noframe.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/index.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/overview-summary.html... Generating /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/target/site/apidocs/help-doc.html... 4 warnings [WARNING] Javadoc Warnings [WARNING] /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/src/main/java/org/dataone/cn/index/generator/IndexTaskGenerator.java:65: warning - @param argument "SystemMetadata" is not a parameter name. [WARNING] /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/src/main/java/org/dataone/cn/index/generator/IndexTaskGenerator.java:90: warning - @param argument "SystemMetadata" is not a parameter name. [WARNING] /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/src/main/java/org/dataone/cn/index/generator/IndexTaskGenerator.java:115: warning - @param argument "SystemMetadata" is not a parameter name. [WARNING] /var/lib/jenkins/jobs/d1_cn_index_generator_stable/workspace/src/main/java/org/dataone/cn/index/generator/filter/HZEventFilter.java:452: warning - @return tag has no arguments. [JENKINS] Archiving javadoc [WARNING] Attempt to (de-)serialize anonymous class hudson.FilePath$32; see: https://jenkins.io/redirect/serialization-of-anonymous-classes/ [WARNING] Attempt to (de-)serialize anonymous class hudson.maven.reporters.MavenArtifactArchiver$2; see: https://jenkins.io/redirect/serialization-of-anonymous-classes/ [WARNING] Attempt to (de-)serialize anonymous class hudson.maven.reporters.MavenFingerprinter$1; see: https://jenkins.io/redirect/serialization-of-anonymous-classes/ Notifying upstream projects of job completion Join notifier requires a CauseAction [INFO] ------------------------------------------------------------------------ [INFO] BUILD SUCCESS [INFO] ------------------------------------------------------------------------ [INFO] Total time: 20.005s [INFO] Finished at: Fri Oct 26 20:45:19 UTC 2018 [INFO] Final Memory: 77M/391M [INFO] ------------------------------------------------------------------------ Waiting for Jenkins to finish collecting data