Build: #9 was successful

Job: Build File Ingest was successful

Stages & jobs

  1. Default Stage

  2. Build Data Admin Docker Image and upload

Build log

The build generated 1,141 lines of output.The output is too long and has been truncated to the last 1,000 lines. Download or view full build log

01-Nov-2018 22:35:45 Downloaded: http://repo.maven.apache.org/maven2/org/apache/maven/plugin-tools/maven-plugin-annotations/3.5.2/maven-plugin-annotations-3.5.2.jar (14 KB at 422.1 KB/sec)
01-Nov-2018 22:35:45 Downloading: http://repo.maven.apache.org/maven2/com/thoughtworks/qdox/qdox/2.0-M8/qdox-2.0-M8.jar
01-Nov-2018 22:35:45 Downloaded: http://repo.maven.apache.org/maven2/org/apache/maven/surefire/surefire-logger-api/2.22.1/surefire-logger-api-2.22.1.jar (14 KB at 343.2 KB/sec)
01-Nov-2018 22:35:45 Downloaded: http://repo.maven.apache.org/maven2/org/apache/maven/surefire/surefire-api/2.22.1/surefire-api-2.22.1.jar (182 KB at 689.6 KB/sec)
01-Nov-2018 22:35:45 Downloaded: http://repo.maven.apache.org/maven2/org/apache/maven/surefire/surefire-booter/2.22.1/surefire-booter-2.22.1.jar (268 KB at 795.2 KB/sec)
01-Nov-2018 22:35:45 Downloaded: http://repo.maven.apache.org/maven2/com/thoughtworks/qdox/qdox/2.0-M8/qdox-2.0-M8.jar (310 KB at 811.0 KB/sec)
01-Nov-2018 22:35:46 Downloaded: http://repo.maven.apache.org/maven2/org/apache/maven/surefire/maven-surefire-common/2.22.1/maven-surefire-common-2.22.1.jar (516 KB at 841.1 KB/sec)
01-Nov-2018 22:35:46 Downloading: https://repo.spring.io/milestone/org/apache/maven/surefire/surefire-junit4/2.22.1/surefire-junit4-2.22.1.pom
01-Nov-2018 22:35:46 Downloading: https://repo.spring.io/snapshot/org/apache/maven/surefire/surefire-junit4/2.22.1/surefire-junit4-2.22.1.pom
01-Nov-2018 22:35:46 Downloading: http://repo.maven.apache.org/maven2/org/apache/maven/surefire/surefire-junit4/2.22.1/surefire-junit4-2.22.1.pom
01-Nov-2018 22:35:46 Downloaded: http://repo.maven.apache.org/maven2/org/apache/maven/surefire/surefire-junit4/2.22.1/surefire-junit4-2.22.1.pom (4 KB at 188.2 KB/sec)
01-Nov-2018 22:35:46 Downloading: https://repo.spring.io/milestone/org/apache/maven/surefire/surefire-providers/2.22.1/surefire-providers-2.22.1.pom
01-Nov-2018 22:35:46 Downloading: https://repo.spring.io/snapshot/org/apache/maven/surefire/surefire-providers/2.22.1/surefire-providers-2.22.1.pom
01-Nov-2018 22:35:46 Downloading: http://repo.maven.apache.org/maven2/org/apache/maven/surefire/surefire-providers/2.22.1/surefire-providers-2.22.1.pom
01-Nov-2018 22:35:46 Downloaded: http://repo.maven.apache.org/maven2/org/apache/maven/surefire/surefire-providers/2.22.1/surefire-providers-2.22.1.pom (3 KB at 135.0 KB/sec)
01-Nov-2018 22:35:46 Downloading: https://repo.spring.io/milestone/org/apache/maven/surefire/surefire-junit4/2.22.1/surefire-junit4-2.22.1.jar
01-Nov-2018 22:35:47 Downloading: https://repo.spring.io/snapshot/org/apache/maven/surefire/surefire-junit4/2.22.1/surefire-junit4-2.22.1.jar
01-Nov-2018 22:35:47 Downloading: http://repo.maven.apache.org/maven2/org/apache/maven/surefire/surefire-junit4/2.22.1/surefire-junit4-2.22.1.jar
01-Nov-2018 22:35:47 Downloaded: http://repo.maven.apache.org/maven2/org/apache/maven/surefire/surefire-junit4/2.22.1/surefire-junit4-2.22.1.jar (83 KB at 757.5 KB/sec)
01-Nov-2018 22:35:47 [INFO]
01-Nov-2018 22:35:47 [INFO] -------------------------------------------------------
01-Nov-2018 22:35:47 [INFO]  T E S T S
01-Nov-2018 22:35:47 [INFO] -------------------------------------------------------
01-Nov-2018 22:35:47 [INFO] Running io.spring.cloud.dataflow.ingest.mapper.fieldset.PersonFieldSetMapperTests
01-Nov-2018 22:35:47 [INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.073 s - in io.spring.cloud.dataflow.ingest.mapper.fieldset.PersonFieldSetMapperTests
01-Nov-2018 22:35:47 [INFO] Running io.spring.cloud.dataflow.ingest.BatchApplicationTests
01-Nov-2018 22:35:48 22:35:48.016 [main] DEBUG org.springframework.test.context.junit4.SpringJUnit4ClassRunner - SpringJUnit4ClassRunner constructor called with [class io.spring.cloud.dataflow.ingest.BatchApplicationTests]
01-Nov-2018 22:35:48 22:35:48.023 [main] DEBUG org.springframework.test.context.BootstrapUtils - Instantiating CacheAwareContextLoaderDelegate from class [org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate]
01-Nov-2018 22:35:48 22:35:48.033 [main] DEBUG org.springframework.test.context.BootstrapUtils - Instantiating BootstrapContext using constructor [public org.springframework.test.context.support.DefaultBootstrapContext(java.lang.Class,org.springframework.test.context.CacheAwareContextLoaderDelegate)]
01-Nov-2018 22:35:48 22:35:48.046 [main] DEBUG org.springframework.test.context.BootstrapUtils - Instantiating TestContextBootstrapper for test class [io.spring.cloud.dataflow.ingest.BatchApplicationTests] from class [org.springframework.test.context.support.DefaultTestContextBootstrapper]
01-Nov-2018 22:35:48 22:35:48.082 [main] DEBUG org.springframework.test.context.support.AbstractDelegatingSmartContextLoader - Delegating to AnnotationConfigContextLoader to process context configuration [ContextConfigurationAttributes@3234e239 declaringClass = 'io.spring.cloud.dataflow.ingest.BatchApplicationTests', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', locations = '{}', inheritLocations = true, initializers = '{}', inheritInitializers = true, name = [null], contextLoaderClass = 'org.springframework.test.context.ContextLoader'].
01-Nov-2018 22:35:48 22:35:48.136 [main] DEBUG org.springframework.test.context.support.ActiveProfilesUtils - Could not find an 'annotation declaring class' for annotation type [org.springframework.test.context.ActiveProfiles] and class [io.spring.cloud.dataflow.ingest.BatchApplicationTests]
01-Nov-2018 22:35:48 22:35:48.137 [main] DEBUG org.springframework.test.context.support.DefaultTestContextBootstrapper - @TestExecutionListeners is not present for class [io.spring.cloud.dataflow.ingest.BatchApplicationTests]: using defaults.
01-Nov-2018 22:35:48 22:35:48.138 [main] INFO org.springframework.test.context.support.DefaultTestContextBootstrapper - Loaded default TestExecutionListener class names from location [META-INF/spring.factories]: [org.springframework.boot.test.mock.mockito.MockitoTestExecutionListener, org.springframework.boot.test.mock.mockito.ResetMocksTestExecutionListener, org.springframework.boot.test.autoconfigure.restdocs.RestDocsTestExecutionListener, org.springframework.boot.test.autoconfigure.web.client.MockRestServiceServerResetTestExecutionListener, org.springframework.boot.test.autoconfigure.web.servlet.MockMvcPrintOnlyOnFailureTestExecutionListener, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverTestExecutionListener, org.springframework.test.context.web.ServletTestExecutionListener, org.springframework.test.context.support.DirtiesContextBeforeModesTestExecutionListener, org.springframework.test.context.support.DependencyInjectionTestExecutionListener, org.springframework.test.context.support.DirtiesContextTestExecutionListener, org.springframework.test.context.transaction.TransactionalTestExecutionListener, org.springframework.test.context.jdbc.SqlScriptsTestExecutionListener]
01-Nov-2018 22:35:48 22:35:48.161 [main] DEBUG org.springframework.test.context.support.DefaultTestContextBootstrapper - Skipping candidate TestExecutionListener [org.springframework.test.context.web.ServletTestExecutionListener] due to a missing dependency. Specify custom listener classes or make the default listener classes and their required dependencies available. Offending class: [javax/servlet/ServletContext]
01-Nov-2018 22:35:48 22:35:48.170 [main] INFO org.springframework.test.context.support.DefaultTestContextBootstrapper - Using TestExecutionListeners: [org.springframework.test.context.support.DirtiesContextBeforeModesTestExecutionListener@4df828d7, org.springframework.boot.test.mock.mockito.MockitoTestExecutionListener@b59d31, org.springframework.test.context.support.DependencyInjectionTestExecutionListener@62fdb4a6, org.springframework.test.context.support.DirtiesContextTestExecutionListener@11e21d0e, org.springframework.test.context.transaction.TransactionalTestExecutionListener@1dd02175, org.springframework.test.context.jdbc.SqlScriptsTestExecutionListener@31206beb, org.springframework.boot.test.mock.mockito.ResetMocksTestExecutionListener@3e77a1ed, org.springframework.boot.test.autoconfigure.restdocs.RestDocsTestExecutionListener@3ffcd140, org.springframework.boot.test.autoconfigure.web.client.MockRestServiceServerResetTestExecutionListener@23bb8443, org.springframework.boot.test.autoconfigure.web.servlet.MockMvcPrintOnlyOnFailureTestExecutionListener@1176dcec, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverTestExecutionListener@120d6fe6]
01-Nov-2018 22:35:48 22:35:48.172 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved @ProfileValueSourceConfiguration [null] for test class [io.spring.cloud.dataflow.ingest.BatchApplicationTests]
01-Nov-2018 22:35:48 22:35:48.172 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved ProfileValueSource type [class org.springframework.test.annotation.SystemProfileValueSource] for class [io.spring.cloud.dataflow.ingest.BatchApplicationTests]
01-Nov-2018 22:35:48 22:35:48.173 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved @ProfileValueSourceConfiguration [null] for test class [io.spring.cloud.dataflow.ingest.BatchApplicationTests]
01-Nov-2018 22:35:48 22:35:48.173 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved ProfileValueSource type [class org.springframework.test.annotation.SystemProfileValueSource] for class [io.spring.cloud.dataflow.ingest.BatchApplicationTests]
01-Nov-2018 22:35:48 22:35:48.173 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved @ProfileValueSourceConfiguration [null] for test class [io.spring.cloud.dataflow.ingest.BatchApplicationTests]
01-Nov-2018 22:35:48 22:35:48.174 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved ProfileValueSource type [class org.springframework.test.annotation.SystemProfileValueSource] for class [io.spring.cloud.dataflow.ingest.BatchApplicationTests]
01-Nov-2018 22:35:48 22:35:48.175 [main] DEBUG org.springframework.test.context.support.AbstractDirtiesContextTestExecutionListener - Before test class: context [DefaultTestContext@453da22c testClass = BatchApplicationTests, testInstance = [null], testMethod = [null], testException = [null], mergedContextConfiguration = [MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]], attributes = map[[empty]]], class annotated with @DirtiesContext [false] with mode [null].
01-Nov-2018 22:35:48 22:35:48.176 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved @ProfileValueSourceConfiguration [null] for test class [io.spring.cloud.dataflow.ingest.BatchApplicationTests]
01-Nov-2018 22:35:48 22:35:48.176 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved ProfileValueSource type [class org.springframework.test.annotation.SystemProfileValueSource] for class [io.spring.cloud.dataflow.ingest.BatchApplicationTests]
01-Nov-2018 22:35:48 22:35:48.182 [main] DEBUG org.springframework.test.context.support.DependencyInjectionTestExecutionListener - Performing dependency injection for test context [[DefaultTestContext@453da22c testClass = BatchApplicationTests, testInstance = io.spring.cloud.dataflow.ingest.BatchApplicationTests@23a5fd2, testMethod = [null], testException = [null], mergedContextConfiguration = [MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]], attributes = map[[empty]]]].
01-Nov-2018 22:35:48 22:35:48.183 [main] DEBUG org.springframework.test.context.support.AbstractDelegatingSmartContextLoader - Delegating to AnnotationConfigContextLoader to load context from [MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]].
01-Nov-2018 22:35:48 22:35:48.184 [main] DEBUG org.springframework.test.context.support.AbstractGenericContextLoader - Loading ApplicationContext for merged context configuration [[MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]]].
01-Nov-2018 22:35:48 22:35:48.229 [main] DEBUG org.springframework.core.env.StandardEnvironment - Activating profiles []
01-Nov-2018 22:35:48 22:35:48.229 [main] DEBUG org.springframework.test.context.support.AnnotationConfigContextLoader - Registering annotated classes: {class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}
01-Nov-2018 22:35:48 22:35:48.272 [main] DEBUG org.springframework.context.support.GenericApplicationContext - Refreshing org.springframework.context.support.GenericApplicationContext@770c2e6b
01-Nov-2018 22:35:48 22:35:48.291 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.context.annotation.internalConfigurationAnnotationProcessor'
01-Nov-2018 22:35:48 22:35:48.735 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.condition.BeanTypeRegistry'
01-Nov-2018 22:35:49 22:35:49.061 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'propertySourcesPlaceholderConfigurer'
01-Nov-2018 22:35:49 22:35:49.071 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.test.mock.mockito.MockitoPostProcessor'
01-Nov-2018 22:35:49 22:35:49.080 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'stepScope'
01-Nov-2018 22:35:49 22:35:49.081 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'jobScope'
01-Nov-2018 22:35:49 22:35:49.111 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerProcessor'
01-Nov-2018 22:35:49 22:35:49.113 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.context.properties.ConfigurationBeanFactoryMetadata'
01-Nov-2018 22:35:49 22:35:49.115 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.context.event.internalEventListenerFactory'
01-Nov-2018 22:35:49 22:35:49.115 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.transaction.config.internalTransactionalEventListenerFactory'
01-Nov-2018 22:35:49 22:35:49.122 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.context.annotation.internalAutowiredAnnotationProcessor'
01-Nov-2018 22:35:49 22:35:49.123 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.context.annotation.internalCommonAnnotationProcessor'
01-Nov-2018 22:35:49 22:35:49.130 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.test.mock.mockito.MockitoPostProcessor$SpyPostProcessor'
01-Nov-2018 22:35:49 22:35:49.132 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.context.properties.ConfigurationPropertiesBindingPostProcessor'
01-Nov-2018 22:35:49 22:35:49.136 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'dataSourceInitializerPostProcessor'
01-Nov-2018 22:35:49 22:35:49.164 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'persistenceExceptionTranslationPostProcessor'
01-Nov-2018 22:35:49 22:35:49.167 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'persistenceExceptionTranslationPostProcessor' via factory method to bean named 'environment'
01-Nov-2018 22:35:49 22:35:49.193 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.aop.config.internalAutoProxyCreator'
01-Nov-2018 22:35:49 22:35:49.214 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'batchTaskExecutionListenerBeanPostProcessor'
01-Nov-2018 22:35:49 22:35:49.214 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.cloud.task.batch.configuration.TaskBatchAutoConfiguration'
01-Nov-2018 22:35:49 22:35:49.220 [main] INFO org.springframework.context.support.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'org.springframework.cloud.task.batch.configuration.TaskBatchAutoConfiguration' of type [org.springframework.cloud.task.batch.configuration.TaskBatchAutoConfiguration$$EnhancerBySpringCGLIB$$1942b21c] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
01-Nov-2018 22:35:49 22:35:49.222 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.transaction.config.internalTransactionAdvisor'
01-Nov-2018 22:35:49 22:35:49.222 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration'
01-Nov-2018 22:35:49 22:35:49.234 [main] INFO org.springframework.context.support.PostProcessorRegistrationDelegate$BeanPostProcessorChecker - Bean 'org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration' of type [org.springframework.transaction.annotation.ProxyTransactionManagementConfiguration$$EnhancerBySpringCGLIB$$93d30690] is not eligible for getting processed by all BeanPostProcessors (for example: not eligible for auto-proxying)
01-Nov-2018 22:35:49 22:35:49.252 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'transactionAttributeSource'
01-Nov-2018 22:35:49 22:35:49.259 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'transactionInterceptor'
01-Nov-2018 22:35:49 22:35:49.309 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'batchConfiguration'
01-Nov-2018 22:35:49 22:35:49.310 [main] DEBUG org.springframework.core.LocalVariableTableParameterNameDiscoverer - Cannot find '.class' file for class [class io.spring.cloud.dataflow.ingest.config.BatchConfiguration$$EnhancerBySpringCGLIB$$261b5617] - unable to determine constructor/method parameter names
01-Nov-2018 22:35:49 22:35:49.311 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'dataSource'
01-Nov-2018 22:35:49 22:35:49.311 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.jdbc.DataSourceConfiguration$Hikari'
01-Nov-2018 22:35:49 22:35:49.316 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'spring.datasource-org.springframework.boot.autoconfigure.jdbc.DataSourceProperties'
01-Nov-2018 22:35:49 22:35:49.336 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'dataSource' via factory method to bean named 'spring.datasource-org.springframework.boot.autoconfigure.jdbc.DataSourceProperties'
01-Nov-2018 22:35:49 22:35:49.368 [main] DEBUG com.zaxxer.hikari.HikariConfig - Driver class org.h2.Driver found in Thread context class loader sun.misc.Launcher$AppClassLoader@4aa298b7
01-Nov-2018 22:35:49 22:35:49.391 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.jdbc.DataSourceInitializerInvoker'
01-Nov-2018 22:35:49 22:35:49.395 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'org.springframework.boot.autoconfigure.jdbc.DataSourceInitializerInvoker' via constructor to bean named 'spring.datasource-org.springframework.boot.autoconfigure.jdbc.DataSourceProperties'
01-Nov-2018 22:35:49 22:35:49.395 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'org.springframework.boot.autoconfigure.jdbc.DataSourceInitializerInvoker' via constructor to bean named 'org.springframework.context.support.GenericApplicationContext@770c2e6b'
01-Nov-2018 22:35:49 22:35:49.411 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:49 22:35:49.412 [main] DEBUG com.zaxxer.hikari.HikariConfig - HikariPool-1 - configuration:
01-Nov-2018 22:35:49 22:35:49.415 [main] DEBUG com.zaxxer.hikari.HikariConfig - allowPoolSuspension.............false
01-Nov-2018 22:35:49 22:35:49.415 [main] DEBUG com.zaxxer.hikari.HikariConfig - autoCommit......................true
01-Nov-2018 22:35:49 22:35:49.416 [main] DEBUG com.zaxxer.hikari.HikariConfig - catalog.........................none
01-Nov-2018 22:35:49 22:35:49.416 [main] DEBUG com.zaxxer.hikari.HikariConfig - connectionInitSql...............none
01-Nov-2018 22:35:49 22:35:49.416 [main] DEBUG com.zaxxer.hikari.HikariConfig - connectionTestQuery.............none
01-Nov-2018 22:35:49 22:35:49.416 [main] DEBUG com.zaxxer.hikari.HikariConfig - connectionTimeout...............30000
01-Nov-2018 22:35:49 22:35:49.416 [main] DEBUG com.zaxxer.hikari.HikariConfig - dataSource......................none
01-Nov-2018 22:35:49 22:35:49.416 [main] DEBUG com.zaxxer.hikari.HikariConfig - dataSourceClassName.............none
01-Nov-2018 22:35:49 22:35:49.416 [main] DEBUG com.zaxxer.hikari.HikariConfig - dataSourceJNDI..................none
01-Nov-2018 22:35:49 22:35:49.417 [main] DEBUG com.zaxxer.hikari.HikariConfig - dataSourceProperties............{password=<masked>}
01-Nov-2018 22:35:49 22:35:49.417 [main] DEBUG com.zaxxer.hikari.HikariConfig - driverClassName................."org.h2.Driver"
01-Nov-2018 22:35:49 22:35:49.417 [main] DEBUG com.zaxxer.hikari.HikariConfig - healthCheckProperties...........{}
01-Nov-2018 22:35:49 22:35:49.417 [main] DEBUG com.zaxxer.hikari.HikariConfig - healthCheckRegistry.............none
01-Nov-2018 22:35:49 22:35:49.418 [main] DEBUG com.zaxxer.hikari.HikariConfig - idleTimeout.....................600000
01-Nov-2018 22:35:49 22:35:49.418 [main] DEBUG com.zaxxer.hikari.HikariConfig - initializationFailTimeout.......1
01-Nov-2018 22:35:49 22:35:49.418 [main] DEBUG com.zaxxer.hikari.HikariConfig - isolateInternalQueries..........false
01-Nov-2018 22:35:49 22:35:49.418 [main] DEBUG com.zaxxer.hikari.HikariConfig - jdbcUrl.........................jdbc:h2:mem:testdb;DB_CLOSE_DELAY=-1;DB_CLOSE_ON_EXIT=FALSE
01-Nov-2018 22:35:49 22:35:49.418 [main] DEBUG com.zaxxer.hikari.HikariConfig - leakDetectionThreshold..........0
01-Nov-2018 22:35:49 22:35:49.418 [main] DEBUG com.zaxxer.hikari.HikariConfig - maxLifetime.....................1800000
01-Nov-2018 22:35:49 22:35:49.418 [main] DEBUG com.zaxxer.hikari.HikariConfig - maximumPoolSize.................10
01-Nov-2018 22:35:49 22:35:49.418 [main] DEBUG com.zaxxer.hikari.HikariConfig - metricRegistry..................none
01-Nov-2018 22:35:49 22:35:49.419 [main] DEBUG com.zaxxer.hikari.HikariConfig - metricsTrackerFactory...........none
01-Nov-2018 22:35:49 22:35:49.419 [main] DEBUG com.zaxxer.hikari.HikariConfig - minimumIdle.....................10
01-Nov-2018 22:35:49 22:35:49.419 [main] DEBUG com.zaxxer.hikari.HikariConfig - password........................<masked>
01-Nov-2018 22:35:49 22:35:49.419 [main] DEBUG com.zaxxer.hikari.HikariConfig - poolName........................"HikariPool-1"
01-Nov-2018 22:35:49 22:35:49.419 [main] DEBUG com.zaxxer.hikari.HikariConfig - readOnly........................false
01-Nov-2018 22:35:49 22:35:49.419 [main] DEBUG com.zaxxer.hikari.HikariConfig - registerMbeans..................false
01-Nov-2018 22:35:49 22:35:49.419 [main] DEBUG com.zaxxer.hikari.HikariConfig - scheduledExecutor...............none
01-Nov-2018 22:35:49 22:35:49.419 [main] DEBUG com.zaxxer.hikari.HikariConfig - schema..........................none
01-Nov-2018 22:35:49 22:35:49.419 [main] DEBUG com.zaxxer.hikari.HikariConfig - threadFactory...................internal
01-Nov-2018 22:35:49 22:35:49.419 [main] DEBUG com.zaxxer.hikari.HikariConfig - transactionIsolation............default
01-Nov-2018 22:35:49 22:35:49.420 [main] DEBUG com.zaxxer.hikari.HikariConfig - username........................"sa"
01-Nov-2018 22:35:49 22:35:49.420 [main] DEBUG com.zaxxer.hikari.HikariConfig - validationTimeout...............5000
01-Nov-2018 22:35:49 22:35:49.420 [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Starting...
01-Nov-2018 22:35:49 22:35:49.671 [main] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection conn0: url=jdbc:h2:mem:testdb user=SA
01-Nov-2018 22:35:49 22:35:49.672 [main] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Start completed.
01-Nov-2018 22:35:49 22:35:49.690 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:49 22:35:49.696 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:49 22:35:49.698 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - Executing SQL script from URL [file:/opt/bamboo-home/xml-data/build-dir/SCD-FILEINGEST-BSCDL/batch/file-ingest/target/classes/schema-all.sql]
01-Nov-2018 22:35:49 22:35:49.721 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - 0 returned as update count for SQL: CREATE TABLE IF NOT EXISTS people ( person_id BIGINT NOT NULL AUTO_INCREMENT, first_name VARCHAR(20), last_name VARCHAR(20), PRIMARY KEY (person_id) )
01-Nov-2018 22:35:49 22:35:49.721 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - Executed SQL script from URL [file:/opt/bamboo-home/xml-data/build-dir/SCD-FILEINGEST-BSCDL/batch/file-ingest/target/classes/schema-all.sql] in 23 ms.
01-Nov-2018 22:35:49 22:35:49.721 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:49 22:35:49.725 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'taskLifecycleListener'
01-Nov-2018 22:35:49 22:35:49.725 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.cloud.task.configuration.SimpleTaskAutoConfiguration'
01-Nov-2018 22:35:49 22:35:49.732 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'spring.cloud.task-org.springframework.cloud.task.configuration.TaskProperties'
01-Nov-2018 22:35:49 22:35:49.752 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:49 22:35:49.752 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:49 22:35:49.754 [main] DEBUG org.springframework.cloud.task.configuration.SimpleTaskAutoConfiguration - Using org.springframework.cloud.task.configuration.DefaultTaskConfigurer TaskConfigurer
01-Nov-2018 22:35:49 22:35:49.754 [main] DEBUG org.springframework.cloud.task.configuration.DefaultTaskConfigurer - No EntityManager was found, using DataSourceTransactionManager
01-Nov-2018 22:35:49 22:35:49.759 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'taskNameResolver'
01-Nov-2018 22:35:49 22:35:49.772 [HikariPool-1 housekeeper] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Pool stats (total=1, active=0, idle=1, waiting=0)
01-Nov-2018 22:35:49 22:35:49.778 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection conn1: url=jdbc:h2:mem:testdb user=SA
01-Nov-2018 22:35:49 22:35:49.779 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection conn2: url=jdbc:h2:mem:testdb user=SA
01-Nov-2018 22:35:49 22:35:49.784 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection conn3: url=jdbc:h2:mem:testdb user=SA
01-Nov-2018 22:35:49 22:35:49.784 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'jobBuilders'
01-Nov-2018 22:35:49 22:35:49.785 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration'
01-Nov-2018 22:35:49 22:35:49.788 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection conn4: url=jdbc:h2:mem:testdb user=SA
01-Nov-2018 22:35:49 22:35:49.789 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection conn5: url=jdbc:h2:mem:testdb user=SA
01-Nov-2018 22:35:49 22:35:49.789 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection conn6: url=jdbc:h2:mem:testdb user=SA
01-Nov-2018 22:35:49 22:35:49.790 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection conn7: url=jdbc:h2:mem:testdb user=SA
01-Nov-2018 22:35:49 22:35:49.792 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection conn8: url=jdbc:h2:mem:testdb user=SA
01-Nov-2018 22:35:49 22:35:49.794 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Added connection conn9: url=jdbc:h2:mem:testdb user=SA
01-Nov-2018 22:35:49 22:35:49.794 [HikariPool-1 connection adder] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - After adding stats (total=10, active=0, idle=10, waiting=0)
01-Nov-2018 22:35:49 22:35:49.799 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'jobRepository'
01-Nov-2018 22:35:49 22:35:49.829 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'stepBuilders'
01-Nov-2018 22:35:49 22:35:49.831 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'transactionManager'
01-Nov-2018 22:35:49 22:35:49.841 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'batchConfiguration' via constructor to bean named 'dataSource'
01-Nov-2018 22:35:49 22:35:49.842 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'batchConfiguration' via constructor to bean named 'jobBuilders'
01-Nov-2018 22:35:49 22:35:49.842 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'batchConfiguration' via constructor to bean named 'stepBuilders'
01-Nov-2018 22:35:49 22:35:49.842 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'batchConfiguration' via constructor to bean named 'org.springframework.context.support.GenericApplicationContext@770c2e6b'
01-Nov-2018 22:35:49 22:35:49.845 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'batchApplicationTests.BatchTestConfiguration'
01-Nov-2018 22:35:49 22:35:49.848 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.batch.core.configuration.annotation.ScopeConfiguration'
01-Nov-2018 22:35:49 22:35:49.851 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'jobLauncher'
01-Nov-2018 22:35:49 22:35:49.859 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'jobRegistry'
01-Nov-2018 22:35:49 22:35:49.869 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'jobExplorer'
01-Nov-2018 22:35:49 22:35:49.878 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'reader'
01-Nov-2018 22:35:49 22:35:49.889 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'processor'
01-Nov-2018 22:35:49 22:35:49.897 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'writer'
01-Nov-2018 22:35:49 22:35:49.903 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'ingestJob'
01-Nov-2018 22:35:49 22:35:49.905 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'step1'
01-Nov-2018 22:35:49 22:35:49.918 [main] WARN org.springframework.batch.core.listener.AbstractListenerFactoryBean - org.springframework.batch.item.ItemStreamReader is an interface. The implementing class will not be queried for annotation based listener configurations. If using @StepScope on a @Bean method, be sure to return the implementing class so listener annotations can be used.
01-Nov-2018 22:35:49 22:35:49.963 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'taskBatchExecutionListener'
01-Nov-2018 22:35:49 22:35:49.963 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.cloud.task.batch.configuration.TaskBatchAutoConfiguration$TaskBatchExecutionListenerAutoconfiguration'
01-Nov-2018 22:35:49 22:35:49.968 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'taskExplorer'
01-Nov-2018 22:35:49 22:35:49.973 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'taskBatchExecutionListener' via factory method to bean named 'taskExplorer'
01-Nov-2018 22:35:49 22:35:49.982 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'jobLauncherTestUtils'
01-Nov-2018 22:35:49 22:35:49.991 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.AutoConfigurationPackages'
01-Nov-2018 22:35:49 22:35:49.993 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.context.PropertyPlaceholderAutoConfiguration'
01-Nov-2018 22:35:49 22:35:49.996 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.jmx.JmxAutoConfiguration'
01-Nov-2018 22:35:50 22:35:50.004 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'mbeanExporter'
01-Nov-2018 22:35:50 22:35:50.005 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'objectNamingStrategy'
01-Nov-2018 22:35:50 22:35:50.011 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'mbeanExporter' via factory method to bean named 'objectNamingStrategy'
01-Nov-2018 22:35:50 22:35:50.019 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'mbeanServer'
01-Nov-2018 22:35:50 22:35:50.072 [main] DEBUG org.springframework.jmx.support.JmxUtils - Found MBeanServer: com.sun.jmx.mbeanserver.JmxMBeanServer@22db8f4
01-Nov-2018 22:35:50 22:35:50.105 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.jdbc.DataSourceJmxConfiguration$Hikari'
01-Nov-2018 22:35:50 22:35:50.109 [main] DEBUG org.springframework.core.LocalVariableTableParameterNameDiscoverer - Cannot find '.class' file for class [class org.springframework.boot.autoconfigure.jdbc.DataSourceJmxConfiguration$Hikari$$EnhancerBySpringCGLIB$$7d7767fa] - unable to determine constructor/method parameter names
01-Nov-2018 22:35:50 22:35:50.110 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'org.springframework.boot.autoconfigure.jdbc.DataSourceJmxConfiguration$Hikari' via constructor to bean named 'dataSource'
01-Nov-2018 22:35:50 22:35:50.114 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.jdbc.DataSourceJmxConfiguration'
01-Nov-2018 22:35:50 22:35:50.118 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.jdbc.DataSourceAutoConfiguration$PooledDataSourceConfiguration'
01-Nov-2018 22:35:50 22:35:50.121 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.jdbc.metadata.DataSourcePoolMetadataProvidersConfiguration$HikariPoolDataSourceMetadataProviderConfiguration'
01-Nov-2018 22:35:50 22:35:50.125 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'hikariPoolDataSourceMetadataProvider'
01-Nov-2018 22:35:50 22:35:50.140 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.jdbc.metadata.DataSourcePoolMetadataProvidersConfiguration'
01-Nov-2018 22:35:50 22:35:50.143 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.jdbc.DataSourceInitializationConfiguration'
01-Nov-2018 22:35:50 22:35:50.146 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.jdbc.DataSourceAutoConfiguration'
01-Nov-2018 22:35:50 22:35:50.149 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.batch.BatchConfigurerConfiguration$JdbcBatchConfiguration'
01-Nov-2018 22:35:50 22:35:50.152 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'batchConfigurer'
01-Nov-2018 22:35:50 22:35:50.153 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'spring.batch-org.springframework.boot.autoconfigure.batch.BatchProperties'
01-Nov-2018 22:35:50 22:35:50.157 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'batchConfigurer' via factory method to bean named 'spring.batch-org.springframework.boot.autoconfigure.batch.BatchProperties'
01-Nov-2018 22:35:50 22:35:50.157 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'batchConfigurer' via factory method to bean named 'dataSource'
01-Nov-2018 22:35:50 22:35:50.161 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'platformTransactionManagerCustomizers'
01-Nov-2018 22:35:50 22:35:50.161 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.transaction.TransactionAutoConfiguration'
01-Nov-2018 22:35:50 22:35:50.170 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'spring.transaction-org.springframework.boot.autoconfigure.transaction.TransactionProperties'
01-Nov-2018 22:35:50 22:35:50.195 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:50 22:35:50.195 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:50 22:35:50.195 [main] INFO org.springframework.batch.core.repository.support.JobRepositoryFactoryBean - No database type set, using meta data indicating: H2
01-Nov-2018 22:35:50 22:35:50.360 [main] DEBUG org.springframework.transaction.interceptor.NameMatchTransactionAttributeSource - Adding transactional method [*] with attribute [PROPAGATION_REQUIRED,ISOLATION_DEFAULT]
01-Nov-2018 22:35:50 22:35:50.360 [main] DEBUG org.springframework.transaction.interceptor.NameMatchTransactionAttributeSource - Adding transactional method [create*] with attribute [PROPAGATION_REQUIRES_NEW,ISOLATION_SERIALIZABLE]
01-Nov-2018 22:35:50 22:35:50.360 [main] DEBUG org.springframework.transaction.interceptor.NameMatchTransactionAttributeSource - Adding transactional method [getLastJobExecution*] with attribute [PROPAGATION_REQUIRES_NEW,ISOLATION_SERIALIZABLE]
01-Nov-2018 22:35:50 22:35:50.370 [main] INFO org.springframework.batch.core.launch.support.SimpleJobLauncher - No TaskExecutor has been set, defaulting to synchronous executor.
01-Nov-2018 22:35:50 22:35:50.374 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.batch.BatchConfigurerConfiguration'
01-Nov-2018 22:35:50 22:35:50.377 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.batch.BatchAutoConfiguration'
01-Nov-2018 22:35:50 22:35:50.377 [main] DEBUG org.springframework.core.LocalVariableTableParameterNameDiscoverer - Cannot find '.class' file for class [class org.springframework.boot.autoconfigure.batch.BatchAutoConfiguration$$EnhancerBySpringCGLIB$$a955abe2] - unable to determine constructor/method parameter names
01-Nov-2018 22:35:50 22:35:50.378 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'org.springframework.boot.autoconfigure.batch.BatchAutoConfiguration' via constructor to bean named 'spring.batch-org.springframework.boot.autoconfigure.batch.BatchProperties'
01-Nov-2018 22:35:50 22:35:50.381 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'batchDataSourceInitializer'
01-Nov-2018 22:35:50 22:35:50.382 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'batchDataSourceInitializer' via factory method to bean named 'dataSource'
01-Nov-2018 22:35:50 22:35:50.382 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'batchDataSourceInitializer' via factory method to bean named 'org.springframework.context.support.GenericApplicationContext@770c2e6b'
01-Nov-2018 22:35:50 22:35:50.389 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:50 22:35:50.389 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:50 22:35:50.389 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:50 22:35:50.390 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:50 22:35:50.393 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:50 22:35:50.393 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - Executing SQL script from class path resource [org/springframework/batch/core/schema-h2.sql]
01-Nov-2018 22:35:50 22:35:50.399 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - 0 returned as update count for SQL: CREATE TABLE BATCH_JOB_INSTANCE ( JOB_INSTANCE_ID BIGINT IDENTITY NOT NULL PRIMARY KEY , VERSION BIGINT , JOB_NAME VARCHAR(100) NOT NULL, JOB_KEY VARCHAR(32) NOT NULL, constraint JOB_INST_UN unique (JOB_NAME, JOB_KEY) )
01-Nov-2018 22:35:50 22:35:50.415 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - 0 returned as update count for SQL: CREATE TABLE BATCH_JOB_EXECUTION ( JOB_EXECUTION_ID BIGINT IDENTITY NOT NULL PRIMARY KEY , VERSION BIGINT , JOB_INSTANCE_ID BIGINT NOT NULL, CREATE_TIME TIMESTAMP NOT NULL, START_TIME TIMESTAMP DEFAULT NULL , END_TIME TIMESTAMP DEFAULT NULL , STATUS VARCHAR(10) , EXIT_CODE VARCHAR(2500) , EXIT_MESSAGE VARCHAR(2500) , LAST_UPDATED TIMESTAMP, JOB_CONFIGURATION_LOCATION VARCHAR(2500) NULL, constraint JOB_INST_EXEC_FK foreign key (JOB_INSTANCE_ID) references BATCH_JOB_INSTANCE(JOB_INSTANCE_ID) )
01-Nov-2018 22:35:50 22:35:50.418 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - 0 returned as update count for SQL: CREATE TABLE BATCH_JOB_EXECUTION_PARAMS ( JOB_EXECUTION_ID BIGINT NOT NULL , TYPE_CD VARCHAR(6) NOT NULL , KEY_NAME VARCHAR(100) NOT NULL , STRING_VAL VARCHAR(250) , DATE_VAL TIMESTAMP DEFAULT NULL , LONG_VAL BIGINT , DOUBLE_VAL DOUBLE PRECISION , IDENTIFYING CHAR(1) NOT NULL , constraint JOB_EXEC_PARAMS_FK foreign key (JOB_EXECUTION_ID) references BATCH_JOB_EXECUTION(JOB_EXECUTION_ID) )
01-Nov-2018 22:35:50 22:35:50.421 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - 0 returned as update count for SQL: CREATE TABLE BATCH_STEP_EXECUTION ( STEP_EXECUTION_ID BIGINT IDENTITY NOT NULL PRIMARY KEY , VERSION BIGINT NOT NULL, STEP_NAME VARCHAR(100) NOT NULL, JOB_EXECUTION_ID BIGINT NOT NULL, START_TIME TIMESTAMP NOT NULL , END_TIME TIMESTAMP DEFAULT NULL , STATUS VARCHAR(10) , COMMIT_COUNT BIGINT , READ_COUNT BIGINT , FILTER_COUNT BIGINT , WRITE_COUNT BIGINT , READ_SKIP_COUNT BIGINT , WRITE_SKIP_COUNT BIGINT , PROCESS_SKIP_COUNT BIGINT , ROLLBACK_COUNT BIGINT , EXIT_CODE VARCHAR(2500) , EXIT_MESSAGE VARCHAR(2500) , LAST_UPDATED TIMESTAMP, constraint JOB_EXEC_STEP_FK foreign key (JOB_EXECUTION_ID) references BATCH_JOB_EXECUTION(JOB_EXECUTION_ID) )
01-Nov-2018 22:35:50 22:35:50.423 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - 0 returned as update count for SQL: CREATE TABLE BATCH_STEP_EXECUTION_CONTEXT ( STEP_EXECUTION_ID BIGINT NOT NULL PRIMARY KEY, SHORT_CONTEXT VARCHAR(2500) NOT NULL, SERIALIZED_CONTEXT LONGVARCHAR , constraint STEP_EXEC_CTX_FK foreign key (STEP_EXECUTION_ID) references BATCH_STEP_EXECUTION(STEP_EXECUTION_ID) )
01-Nov-2018 22:35:50 22:35:50.425 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - 0 returned as update count for SQL: CREATE TABLE BATCH_JOB_EXECUTION_CONTEXT ( JOB_EXECUTION_ID BIGINT NOT NULL PRIMARY KEY, SHORT_CONTEXT VARCHAR(2500) NOT NULL, SERIALIZED_CONTEXT LONGVARCHAR , constraint JOB_EXEC_CTX_FK foreign key (JOB_EXECUTION_ID) references BATCH_JOB_EXECUTION(JOB_EXECUTION_ID) )
01-Nov-2018 22:35:50 22:35:50.426 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - 0 returned as update count for SQL: CREATE SEQUENCE BATCH_STEP_EXECUTION_SEQ
01-Nov-2018 22:35:50 22:35:50.426 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - 0 returned as update count for SQL: CREATE SEQUENCE BATCH_JOB_EXECUTION_SEQ
01-Nov-2018 22:35:50 22:35:50.427 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - 0 returned as update count for SQL: CREATE SEQUENCE BATCH_JOB_SEQ
01-Nov-2018 22:35:50 22:35:50.427 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - Executed SQL script from class path resource [org/springframework/batch/core/schema-h2.sql] in 34 ms.
01-Nov-2018 22:35:50 22:35:50.427 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:50 22:35:50.428 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'jobLauncherCommandLineRunner'
01-Nov-2018 22:35:50 22:35:50.429 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'jobLauncherCommandLineRunner' via factory method to bean named 'jobLauncher'
01-Nov-2018 22:35:50 22:35:50.429 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'jobLauncherCommandLineRunner' via factory method to bean named 'jobExplorer'
01-Nov-2018 22:35:50 22:35:50.429 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'jobLauncherCommandLineRunner' via factory method to bean named 'jobRepository'
01-Nov-2018 22:35:50 22:35:50.438 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'jobExecutionExitCodeGenerator'
01-Nov-2018 22:35:50 22:35:50.442 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'jobOperator'
01-Nov-2018 22:35:50 22:35:50.443 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'jobOperator' via factory method to bean named 'jobExplorer'
01-Nov-2018 22:35:50 22:35:50.443 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'jobOperator' via factory method to bean named 'jobLauncher'
01-Nov-2018 22:35:50 22:35:50.443 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'jobOperator' via factory method to bean named 'jobRegistry'
01-Nov-2018 22:35:50 22:35:50.444 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'jobOperator' via factory method to bean named 'jobRepository'
01-Nov-2018 22:35:50 22:35:50.483 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.context.ConfigurationPropertiesAutoConfiguration'
01-Nov-2018 22:35:50 22:35:50.486 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.dao.PersistenceExceptionTranslationAutoConfiguration'
01-Nov-2018 22:35:50 22:35:50.490 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.info.ProjectInfoAutoConfiguration'
01-Nov-2018 22:35:50 22:35:50.490 [main] DEBUG org.springframework.core.LocalVariableTableParameterNameDiscoverer - Cannot find '.class' file for class [class org.springframework.boot.autoconfigure.info.ProjectInfoAutoConfiguration$$EnhancerBySpringCGLIB$$cfcd13a9] - unable to determine constructor/method parameter names
01-Nov-2018 22:35:50 22:35:50.492 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'spring.info-org.springframework.boot.autoconfigure.info.ProjectInfoProperties'
01-Nov-2018 22:35:50 22:35:50.495 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'org.springframework.boot.autoconfigure.info.ProjectInfoAutoConfiguration' via constructor to bean named 'spring.info-org.springframework.boot.autoconfigure.info.ProjectInfoProperties'
01-Nov-2018 22:35:50 22:35:50.498 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.jackson.JacksonAutoConfiguration'
01-Nov-2018 22:35:50 22:35:50.501 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'jsonComponentModule'
01-Nov-2018 22:35:50 22:35:50.522 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.jdbc.JdbcTemplateAutoConfiguration$JdbcTemplateConfiguration'
01-Nov-2018 22:35:50 22:35:50.523 [main] DEBUG org.springframework.core.LocalVariableTableParameterNameDiscoverer - Cannot find '.class' file for class [class org.springframework.boot.autoconfigure.jdbc.JdbcTemplateAutoConfiguration$JdbcTemplateConfiguration$$EnhancerBySpringCGLIB$$ac5e34fd] - unable to determine constructor/method parameter names
01-Nov-2018 22:35:50 22:35:50.524 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'spring.jdbc-org.springframework.boot.autoconfigure.jdbc.JdbcProperties'
01-Nov-2018 22:35:50 22:35:50.526 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'org.springframework.boot.autoconfigure.jdbc.JdbcTemplateAutoConfiguration$JdbcTemplateConfiguration' via constructor to bean named 'dataSource'
01-Nov-2018 22:35:50 22:35:50.526 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'org.springframework.boot.autoconfigure.jdbc.JdbcTemplateAutoConfiguration$JdbcTemplateConfiguration' via constructor to bean named 'spring.jdbc-org.springframework.boot.autoconfigure.jdbc.JdbcProperties'
01-Nov-2018 22:35:50 22:35:50.530 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'jdbcTemplate'
01-Nov-2018 22:35:50 22:35:50.558 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.jdbc.JdbcTemplateAutoConfiguration$NamedParameterJdbcTemplateConfiguration'
01-Nov-2018 22:35:50 22:35:50.562 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'namedParameterJdbcTemplate'
01-Nov-2018 22:35:50 22:35:50.564 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'namedParameterJdbcTemplate' via factory method to bean named 'jdbcTemplate'
01-Nov-2018 22:35:50 22:35:50.578 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.jdbc.JdbcTemplateAutoConfiguration'
01-Nov-2018 22:35:50 22:35:50.582 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.task.TaskExecutionAutoConfiguration'
01-Nov-2018 22:35:50 22:35:50.582 [main] DEBUG org.springframework.core.LocalVariableTableParameterNameDiscoverer - Cannot find '.class' file for class [class org.springframework.boot.autoconfigure.task.TaskExecutionAutoConfiguration$$EnhancerBySpringCGLIB$$1f729f66] - unable to determine constructor/method parameter names
01-Nov-2018 22:35:50 22:35:50.584 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'spring.task.execution-org.springframework.boot.autoconfigure.task.TaskExecutionProperties'
01-Nov-2018 22:35:50 22:35:50.587 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'org.springframework.boot.autoconfigure.task.TaskExecutionAutoConfiguration' via constructor to bean named 'spring.task.execution-org.springframework.boot.autoconfigure.task.TaskExecutionProperties'
01-Nov-2018 22:35:50 22:35:50.591 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'taskExecutorBuilder'
01-Nov-2018 22:35:50 22:35:50.601 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.task.TaskSchedulingAutoConfiguration'
01-Nov-2018 22:35:50 22:35:50.605 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'taskSchedulerBuilder'
01-Nov-2018 22:35:50 22:35:50.606 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'spring.task.scheduling-org.springframework.boot.autoconfigure.task.TaskSchedulingProperties'
01-Nov-2018 22:35:50 22:35:50.609 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'taskSchedulerBuilder' via factory method to bean named 'spring.task.scheduling-org.springframework.boot.autoconfigure.task.TaskSchedulingProperties'
01-Nov-2018 22:35:50 22:35:50.616 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.jdbc.DataSourceTransactionManagerAutoConfiguration$DataSourceTransactionManagerConfiguration'
01-Nov-2018 22:35:50 22:35:50.616 [main] DEBUG org.springframework.core.LocalVariableTableParameterNameDiscoverer - Cannot find '.class' file for class [class org.springframework.boot.autoconfigure.jdbc.DataSourceTransactionManagerAutoConfiguration$DataSourceTransactionManagerConfiguration$$EnhancerBySpringCGLIB$$40d39eff] - unable to determine constructor/method parameter names
01-Nov-2018 22:35:50 22:35:50.617 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'org.springframework.boot.autoconfigure.jdbc.DataSourceTransactionManagerAutoConfiguration$DataSourceTransactionManagerConfiguration' via constructor to bean named 'dataSource'
01-Nov-2018 22:35:50 22:35:50.621 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.jdbc.DataSourceTransactionManagerAutoConfiguration'
01-Nov-2018 22:35:50 22:35:50.624 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.transaction.TransactionAutoConfiguration$EnableTransactionManagementConfiguration$CglibAutoProxyConfiguration'
01-Nov-2018 22:35:50 22:35:50.628 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.transaction.TransactionAutoConfiguration$EnableTransactionManagementConfiguration'
01-Nov-2018 22:35:50 22:35:50.631 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.boot.autoconfigure.transaction.TransactionAutoConfiguration$TransactionTemplateConfiguration'
01-Nov-2018 22:35:50 22:35:50.632 [main] DEBUG org.springframework.core.LocalVariableTableParameterNameDiscoverer - Cannot find '.class' file for class [class org.springframework.boot.autoconfigure.transaction.TransactionAutoConfiguration$TransactionTemplateConfiguration$$EnhancerBySpringCGLIB$$925d63d2] - unable to determine constructor/method parameter names
01-Nov-2018 22:35:50 22:35:50.633 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Autowiring by type from bean name 'org.springframework.boot.autoconfigure.transaction.TransactionAutoConfiguration$TransactionTemplateConfiguration' via constructor to bean named 'transactionManager'
01-Nov-2018 22:35:50 22:35:50.636 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'transactionTemplate'
01-Nov-2018 22:35:50 22:35:50.648 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.cloud.task.configuration.ResourceLoadingAutoConfiguration$LocalResourceLoadingAutoConfiguration'
01-Nov-2018 22:35:50 22:35:50.651 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'delegatingResourceLoader'
01-Nov-2018 22:35:50 22:35:50.666 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'org.springframework.cloud.task.configuration.ResourceLoadingAutoConfiguration'
01-Nov-2018 22:35:50 22:35:50.669 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'taskRepository'
01-Nov-2018 22:35:50 22:35:50.686 [main] DEBUG org.springframework.beans.factory.support.DefaultListableBeanFactory - Creating shared instance of singleton bean 'taskRepositoryInitializer'
01-Nov-2018 22:35:50 22:35:50.715 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:50 22:35:50.716 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:50 22:35:50.716 [main] DEBUG org.springframework.cloud.task.repository.support.TaskRepositoryInitializer - Initializing task schema for h2 database
01-Nov-2018 22:35:50 22:35:50.716 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:50 22:35:50.716 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - Executing SQL script from class path resource [org/springframework/cloud/task/schema-h2.sql]
01-Nov-2018 22:35:50 22:35:50.719 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - 0 returned as update count for SQL: CREATE TABLE TASK_EXECUTION ( TASK_EXECUTION_ID BIGINT NOT NULL PRIMARY KEY , START_TIME TIMESTAMP DEFAULT NULL , END_TIME TIMESTAMP DEFAULT NULL , TASK_NAME VARCHAR(100) , EXIT_CODE INTEGER , EXIT_MESSAGE VARCHAR(2500) , ERROR_MESSAGE VARCHAR(2500) , LAST_UPDATED TIMESTAMP, EXTERNAL_EXECUTION_ID VARCHAR(255), PARENT_EXECUTION_ID BIGINT )
01-Nov-2018 22:35:50 22:35:50.721 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - 0 returned as update count for SQL: CREATE TABLE TASK_EXECUTION_PARAMS ( TASK_EXECUTION_ID BIGINT NOT NULL , TASK_PARAM VARCHAR(2500) , constraint TASK_EXEC_PARAMS_FK foreign key (TASK_EXECUTION_ID) references TASK_EXECUTION(TASK_EXECUTION_ID) )
01-Nov-2018 22:35:50 22:35:50.724 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - 0 returned as update count for SQL: CREATE TABLE TASK_TASK_BATCH ( TASK_EXECUTION_ID BIGINT NOT NULL , JOB_EXECUTION_ID BIGINT NOT NULL , constraint TASK_EXEC_BATCH_FK foreign key (TASK_EXECUTION_ID) references TASK_EXECUTION(TASK_EXECUTION_ID) )
01-Nov-2018 22:35:50 22:35:50.725 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - 0 returned as update count for SQL: CREATE SEQUENCE TASK_SEQ
01-Nov-2018 22:35:50 22:35:50.726 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - 0 returned as update count for SQL: CREATE TABLE TASK_LOCK ( LOCK_KEY CHAR(36), REGION VARCHAR(100), CLIENT_ID CHAR(36), CREATED_DATE TIMESTAMP NOT NULL, constraint LOCK_PK primary key (LOCK_KEY, REGION) )
01-Nov-2018 22:35:50 22:35:50.726 [main] DEBUG org.springframework.jdbc.datasource.init.ScriptUtils - Executed SQL script from class path resource [org/springframework/cloud/task/schema-h2.sql] in 10 ms.
01-Nov-2018 22:35:50 22:35:50.726 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:50 22:35:50.738 [main] DEBUG org.springframework.jmx.export.annotation.AnnotationMBeanExporter - Registering beans for JMX exposure on startup
01-Nov-2018 22:35:50 22:35:50.739 [main] DEBUG org.springframework.jmx.export.annotation.AnnotationMBeanExporter - Autodetecting user-defined JMX MBeans
01-Nov-2018 22:35:50 22:35:50.740 [main] DEBUG org.springframework.jmx.export.annotation.AnnotationMBeanExporter - Bean with name 'dataSource' has been autodetected for JMX exposure
01-Nov-2018 22:35:50 22:35:50.747 [main] DEBUG org.springframework.jmx.export.annotation.AnnotationMBeanExporter - Located MBean 'dataSource': registering with JMX server as MBean [com.zaxxer.hikari:name=dataSource,type=HikariDataSource]
01-Nov-2018 22:35:50 22:35:50.753 [main] DEBUG org.springframework.context.support.DefaultLifecycleProcessor - Starting beans in phase 0
01-Nov-2018 22:35:50 22:35:50.800 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:50 22:35:50.812 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:50 22:35:50.817 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:50 22:35:50.818 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT into TASK_EXECUTION(TASK_EXECUTION_ID, START_TIME, TASK_NAME, LAST_UPDATED, EXTERNAL_EXECUTION_ID, PARENT_EXECUTION_ID)values (?, ?, ?, ?, ?, ?)]
01-Nov-2018 22:35:50 22:35:50.818 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:50 22:35:50.828 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:50 22:35:50.831 [main] DEBUG org.springframework.cloud.task.repository.support.SimpleTaskRepository - Creating: TaskExecution{executionId=0, parentExecutionId=null, exitCode=null, taskName='org.springframework.context.support.GenericApplicationContext@770c2e6b', startTime=Thu Nov 01 22:35:50 UTC 2018, endTime=null, exitMessage='null', externalExecutionId='null', errorMessage='null', arguments=[]}
01-Nov-2018 22:35:50 22:35:50.832 [main] DEBUG org.springframework.context.support.DefaultLifecycleProcessor - Successfully started bean 'taskLifecycleListener'
01-Nov-2018 22:35:50 22:35:50.836 [main] DEBUG org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate - Storing ApplicationContext in cache under key [[MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]]]
01-Nov-2018 22:35:50 22:35:50.836 [main] DEBUG org.springframework.test.context.cache - Spring test ApplicationContext cache statistics: [DefaultContextCache@64030b91 size = 1, maxSize = 32, parentContextCount = 0, hitCount = 0, missCount = 1]
01-Nov-2018 22:35:50 22:35:50.843 [main] DEBUG org.springframework.test.context.support.AbstractDirtiesContextTestExecutionListener - Before test method: context [DefaultTestContext@453da22c testClass = BatchApplicationTests, testInstance = io.spring.cloud.dataflow.ingest.BatchApplicationTests@23a5fd2, testMethod = testBatchConfigurationFail@BatchApplicationTests, testException = [null], mergedContextConfiguration = [MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]], attributes = map[[empty]]], class annotated with @DirtiesContext [false] with mode [null], method annotated with @DirtiesContext [false] with mode [null].
01-Nov-2018 22:35:50 22:35:50.845 [main] DEBUG org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate - Retrieved ApplicationContext from cache with key [[MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]]]
01-Nov-2018 22:35:50 22:35:50.845 [main] DEBUG org.springframework.test.context.cache - Spring test ApplicationContext cache statistics: [DefaultContextCache@64030b91 size = 1, maxSize = 32, parentContextCount = 0, hitCount = 1, missCount = 1]
01-Nov-2018 22:35:51 22:35:51.041 [main] DEBUG org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration$ReferenceTargetSource - Initializing lazy target object
01-Nov-2018 22:35:51 22:35:51.046 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.getLastJobExecution]: PROPAGATION_REQUIRES_NEW,ISOLATION_SERIALIZABLE
01-Nov-2018 22:35:51 22:35:51.047 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@7646139 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.049 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Changing isolation level of JDBC Connection [HikariProxyConnection@7646139 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to 8
01-Nov-2018 22:35:51 22:35:51.050 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@7646139 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.052 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.053 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_INSTANCE_ID, JOB_NAME from BATCH_JOB_INSTANCE where JOB_NAME = ? and JOB_KEY = ?]
01-Nov-2018 22:35:51 22:35:51.054 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.055 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@7646139 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.055 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Resetting isolation level of JDBC Connection [HikariProxyConnection@7646139 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to 2
01-Nov-2018 22:35:51 22:35:51.055 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@7646139 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.055 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.056 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.createJobExecution]: PROPAGATION_REQUIRES_NEW,ISOLATION_SERIALIZABLE
01-Nov-2018 22:35:51 22:35:51.056 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@1776589441 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.056 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Changing isolation level of JDBC Connection [HikariProxyConnection@1776589441 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to 8
01-Nov-2018 22:35:51 22:35:51.056 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@1776589441 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.057 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.057 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_INSTANCE_ID, JOB_NAME from BATCH_JOB_INSTANCE where JOB_NAME = ? and JOB_KEY = ?]
01-Nov-2018 22:35:51 22:35:51.057 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.057 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_INSTANCE_ID, JOB_NAME from BATCH_JOB_INSTANCE where JOB_NAME = ? and JOB_KEY = ?]
01-Nov-2018 22:35:51 22:35:51.059 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.059 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT into BATCH_JOB_INSTANCE(JOB_INSTANCE_ID, JOB_NAME, JOB_KEY, VERSION) values (?, ?, ?, ?)]
01-Nov-2018 22:35:51 22:35:51.061 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.061 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT into BATCH_JOB_EXECUTION(JOB_EXECUTION_ID, JOB_INSTANCE_ID, START_TIME, END_TIME, STATUS, EXIT_CODE, EXIT_MESSAGE, VERSION, CREATE_TIME, LAST_UPDATED, JOB_CONFIGURATION_LOCATION) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)]
01-Nov-2018 22:35:51 22:35:51.062 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.062 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT into BATCH_JOB_EXECUTION_PARAMS(JOB_EXECUTION_ID, KEY_NAME, TYPE_CD, STRING_VAL, DATE_VAL, LONG_VAL, DOUBLE_VAL, IDENTIFYING) values (?, ?, ?, ?, ?, ?, ?, ?)]
01-Nov-2018 22:35:51 22:35:51.083 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.083 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT INTO BATCH_JOB_EXECUTION_CONTEXT (SHORT_CONTEXT, SERIALIZED_CONTEXT, JOB_EXECUTION_ID) VALUES(?, ?, ?)]
01-Nov-2018 22:35:51 22:35:51.084 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.084 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@1776589441 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.084 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Resetting isolation level of JDBC Connection [HikariProxyConnection@1776589441 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to 2
01-Nov-2018 22:35:51 22:35:51.085 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@1776589441 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.085 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.085 [main] INFO org.springframework.batch.core.launch.support.SimpleJobLauncher - Job: [FlowJob: [name=ingestJob]] launched with the following parameters: [{localFilePath=classpath:missing-data.csv}]
01-Nov-2018 22:35:51 22:35:51.086 [main] DEBUG org.springframework.batch.core.job.AbstractJob - Job execution starting: JobExecution: id=1, version=0, startTime=null, endTime=null, lastUpdated=Thu Nov 01 22:35:51 UTC 2018, status=STARTING, exitStatus=exitCode=UNKNOWN;exitDescription=, job=[JobInstance: id=1, version=0, Job=[ingestJob]], jobParameters=[{localFilePath=classpath:missing-data.csv}]
01-Nov-2018 22:35:51 22:35:51.088 [main] DEBUG org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration$ReferenceTargetSource - Initializing lazy target object
01-Nov-2018 22:35:51 22:35:51.088 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.update]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.088 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@1255395942 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.088 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@1255395942 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.090 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.090 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT VERSION FROM BATCH_JOB_EXECUTION WHERE JOB_EXECUTION_ID=?]
01-Nov-2018 22:35:51 22:35:51.092 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.092 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT COUNT(*) FROM BATCH_JOB_EXECUTION WHERE JOB_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.096 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.096 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [UPDATE BATCH_JOB_EXECUTION set START_TIME = ?, END_TIME = ?,  STATUS = ?, EXIT_CODE = ?, EXIT_MESSAGE = ?, VERSION = ?, CREATE_TIME = ?, LAST_UPDATED = ? where JOB_EXECUTION_ID = ? and VERSION = ?]
01-Nov-2018 22:35:51 22:35:51.098 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.098 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@1255395942 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.098 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@1255395942 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.098 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.098 [main] INFO org.springframework.cloud.task.batch.listener.TaskBatchExecutionListener - The job execution id 1 was run within the task execution 1
01-Nov-2018 22:35:51 22:35:51.099 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.099 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT INTO TASK_TASK_BATCH VALUES(?, ?)]
01-Nov-2018 22:35:51 22:35:51.099 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:51 22:35:51.099 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.100 [main] DEBUG org.springframework.batch.core.job.flow.support.SimpleFlow - Resuming state=ingestJob.ingest with status=UNKNOWN
01-Nov-2018 22:35:51 22:35:51.100 [main] DEBUG org.springframework.batch.core.job.flow.support.SimpleFlow - Handling state=ingestJob.ingest
01-Nov-2018 22:35:51 22:35:51.100 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.getStepExecutionCount]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.100 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@836782867 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.100 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@836782867 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.101 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.101 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_EXECUTION_ID, START_TIME, END_TIME, STATUS, EXIT_CODE, EXIT_MESSAGE, CREATE_TIME, LAST_UPDATED, VERSION, JOB_CONFIGURATION_LOCATION from BATCH_JOB_EXECUTION where JOB_INSTANCE_ID = ? order by JOB_EXECUTION_ID desc]
01-Nov-2018 22:35:51 22:35:51.102 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.102 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_EXECUTION_ID, KEY_NAME, TYPE_CD, STRING_VAL, DATE_VAL, LONG_VAL, DOUBLE_VAL, IDENTIFYING from BATCH_JOB_EXECUTION_PARAMS where JOB_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.104 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.104 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT STEP_EXECUTION_ID, STEP_NAME, START_TIME, END_TIME, STATUS, COMMIT_COUNT, READ_COUNT, FILTER_COUNT, WRITE_COUNT, EXIT_CODE, EXIT_MESSAGE, READ_SKIP_COUNT, WRITE_SKIP_COUNT, PROCESS_SKIP_COUNT, ROLLBACK_COUNT, LAST_UPDATED, VERSION from BATCH_STEP_EXECUTION where JOB_EXECUTION_ID = ? order by STEP_EXECUTION_ID]
01-Nov-2018 22:35:51 22:35:51.105 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.105 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@836782867 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.105 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@836782867 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.105 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.105 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.getLastStepExecution]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.105 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@114990534 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.105 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@114990534 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.105 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.106 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_EXECUTION_ID, START_TIME, END_TIME, STATUS, EXIT_CODE, EXIT_MESSAGE, CREATE_TIME, LAST_UPDATED, VERSION, JOB_CONFIGURATION_LOCATION from BATCH_JOB_EXECUTION where JOB_INSTANCE_ID = ? order by JOB_EXECUTION_ID desc]
01-Nov-2018 22:35:51 22:35:51.106 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.106 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_EXECUTION_ID, KEY_NAME, TYPE_CD, STRING_VAL, DATE_VAL, LONG_VAL, DOUBLE_VAL, IDENTIFYING from BATCH_JOB_EXECUTION_PARAMS where JOB_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.106 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.106 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT STEP_EXECUTION_ID, STEP_NAME, START_TIME, END_TIME, STATUS, COMMIT_COUNT, READ_COUNT, FILTER_COUNT, WRITE_COUNT, EXIT_CODE, EXIT_MESSAGE, READ_SKIP_COUNT, WRITE_SKIP_COUNT, PROCESS_SKIP_COUNT, ROLLBACK_COUNT, LAST_UPDATED, VERSION from BATCH_STEP_EXECUTION where JOB_EXECUTION_ID = ? order by STEP_EXECUTION_ID]
01-Nov-2018 22:35:51 22:35:51.106 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.106 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@114990534 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.106 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@114990534 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.107 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.107 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.getStepExecutionCount]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.107 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@134048221 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.107 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@134048221 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.107 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.107 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_EXECUTION_ID, START_TIME, END_TIME, STATUS, EXIT_CODE, EXIT_MESSAGE, CREATE_TIME, LAST_UPDATED, VERSION, JOB_CONFIGURATION_LOCATION from BATCH_JOB_EXECUTION where JOB_INSTANCE_ID = ? order by JOB_EXECUTION_ID desc]
01-Nov-2018 22:35:51 22:35:51.107 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.107 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_EXECUTION_ID, KEY_NAME, TYPE_CD, STRING_VAL, DATE_VAL, LONG_VAL, DOUBLE_VAL, IDENTIFYING from BATCH_JOB_EXECUTION_PARAMS where JOB_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.107 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.107 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT STEP_EXECUTION_ID, STEP_NAME, START_TIME, END_TIME, STATUS, COMMIT_COUNT, READ_COUNT, FILTER_COUNT, WRITE_COUNT, EXIT_CODE, EXIT_MESSAGE, READ_SKIP_COUNT, WRITE_SKIP_COUNT, PROCESS_SKIP_COUNT, ROLLBACK_COUNT, LAST_UPDATED, VERSION from BATCH_STEP_EXECUTION where JOB_EXECUTION_ID = ? order by STEP_EXECUTION_ID]
01-Nov-2018 22:35:51 22:35:51.108 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.108 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@134048221 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.108 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@134048221 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.108 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.108 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.add]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.108 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@130564501 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.108 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@130564501 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.109 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.109 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT into BATCH_STEP_EXECUTION(STEP_EXECUTION_ID, VERSION, STEP_NAME, JOB_EXECUTION_ID, START_TIME, END_TIME, STATUS, COMMIT_COUNT, READ_COUNT, FILTER_COUNT, WRITE_COUNT, EXIT_CODE, EXIT_MESSAGE, READ_SKIP_COUNT, WRITE_SKIP_COUNT, PROCESS_SKIP_COUNT, ROLLBACK_COUNT, LAST_UPDATED) values(?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)]
01-Nov-2018 22:35:51 22:35:51.110 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.110 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT INTO BATCH_STEP_EXECUTION_CONTEXT (SHORT_CONTEXT, SERIALIZED_CONTEXT, STEP_EXECUTION_ID) VALUES(?, ?, ?)]
01-Nov-2018 22:35:51 22:35:51.111 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.111 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@130564501 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.111 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@130564501 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.111 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.111 [main] INFO org.springframework.batch.core.job.SimpleStepHandler - Executing step: [ingest]
01-Nov-2018 22:35:51 22:35:51.111 [main] DEBUG org.springframework.batch.core.step.AbstractStep - Executing: id=1
01-Nov-2018 22:35:51 22:35:51.111 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.update]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.111 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@1429133319 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.111 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@1429133319 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.111 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.111 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [UPDATE BATCH_STEP_EXECUTION set START_TIME = ?, END_TIME = ?, STATUS = ?, COMMIT_COUNT = ?, READ_COUNT = ?, FILTER_COUNT = ?, WRITE_COUNT = ?, EXIT_CODE = ?, EXIT_MESSAGE = ?, VERSION = ?, READ_SKIP_COUNT = ?, PROCESS_SKIP_COUNT = ?, WRITE_SKIP_COUNT = ?, ROLLBACK_COUNT = ?, LAST_UPDATED = ? where STEP_EXECUTION_ID = ? and VERSION = ?]
01-Nov-2018 22:35:51 22:35:51.112 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.112 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT VERSION FROM BATCH_JOB_EXECUTION WHERE JOB_EXECUTION_ID=?]
01-Nov-2018 22:35:51 22:35:51.113 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.113 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@1429133319 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.113 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@1429133319 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.113 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.115 [main] DEBUG org.springframework.batch.core.scope.StepScope - Creating object in scope=step, name=scopedTarget.reader
01-Nov-2018 22:35:51 22:35:51.143 [main] DEBUG org.springframework.batch.core.scope.StepScope - Registered destruction callback in scope=step, name=scopedTarget.reader
01-Nov-2018 22:35:51 22:35:51.146 [main] ERROR org.springframework.batch.core.step.AbstractStep - Encountered an error executing step ingest in job ingestJob
01-Nov-2018 22:35:51 org.springframework.batch.item.ItemStreamException: Failed to initialize the reader
01-Nov-2018 22:35:51         at org.springframework.batch.item.support.AbstractItemCountingItemStreamItemReader.open(AbstractItemCountingItemStreamItemReader.java:152)
01-Nov-2018 22:35:51         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
01-Nov-2018 22:35:51         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
01-Nov-2018 22:35:51         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
01-Nov-2018 22:35:51         at java.lang.reflect.Method.invoke(Method.java:498)
01-Nov-2018 22:35:51         at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343)
01-Nov-2018 22:35:51         at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
01-Nov-2018 22:35:51         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
01-Nov-2018 22:35:51         at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:136)
01-Nov-2018 22:35:51         at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:124)
01-Nov-2018 22:35:51         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
01-Nov-2018 22:35:51         at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
01-Nov-2018 22:35:51         at com.sun.proxy.$Proxy53.open(Unknown Source)
01-Nov-2018 22:35:51         at org.springframework.batch.item.support.CompositeItemStream.open(CompositeItemStream.java:103)
01-Nov-2018 22:35:51         at org.springframework.batch.core.step.tasklet.TaskletStep.open(TaskletStep.java:311)
01-Nov-2018 22:35:51         at org.springframework.batch.core.step.AbstractStep.execute(AbstractStep.java:200)
01-Nov-2018 22:35:51         at org.springframework.batch.core.job.SimpleStepHandler.handleStep(SimpleStepHandler.java:148)
01-Nov-2018 22:35:51         at org.springframework.batch.core.job.flow.JobFlowExecutor.executeStep(JobFlowExecutor.java:68)
01-Nov-2018 22:35:51         at org.springframework.batch.core.job.flow.support.state.StepState.handle(StepState.java:67)
01-Nov-2018 22:35:51         at org.springframework.batch.core.job.flow.support.SimpleFlow.resume(SimpleFlow.java:169)
01-Nov-2018 22:35:51         at org.springframework.batch.core.job.flow.support.SimpleFlow.start(SimpleFlow.java:144)
01-Nov-2018 22:35:51         at org.springframework.batch.core.job.flow.FlowJob.doExecute(FlowJob.java:136)
01-Nov-2018 22:35:51         at org.springframework.batch.core.job.AbstractJob.execute(AbstractJob.java:313)
01-Nov-2018 22:35:51         at org.springframework.batch.core.launch.support.SimpleJobLauncher$1.run(SimpleJobLauncher.java:144)
01-Nov-2018 22:35:51         at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:50)
01-Nov-2018 22:35:51         at org.springframework.batch.core.launch.support.SimpleJobLauncher.run(SimpleJobLauncher.java:137)
01-Nov-2018 22:35:51         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
01-Nov-2018 22:35:51         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
01-Nov-2018 22:35:51         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
01-Nov-2018 22:35:51         at java.lang.reflect.Method.invoke(Method.java:498)
01-Nov-2018 22:35:51         at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343)
01-Nov-2018 22:35:51         at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
01-Nov-2018 22:35:51         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
01-Nov-2018 22:35:51         at org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration$PassthruAdvice.invoke(SimpleBatchConfiguration.java:127)
01-Nov-2018 22:35:51         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
01-Nov-2018 22:35:51         at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
01-Nov-2018 22:35:51         at com.sun.proxy.$Proxy50.run(Unknown Source)
01-Nov-2018 22:35:51         at org.springframework.batch.test.JobLauncherTestUtils.launchJob(JobLauncherTestUtils.java:154)
01-Nov-2018 22:35:51         at io.spring.cloud.dataflow.ingest.BatchApplicationTests.testBatchConfigurationFail(BatchApplicationTests.java:61)
01-Nov-2018 22:35:51         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
01-Nov-2018 22:35:51         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
01-Nov-2018 22:35:51         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
01-Nov-2018 22:35:51         at java.lang.reflect.Method.invoke(Method.java:498)
01-Nov-2018 22:35:51         at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
01-Nov-2018 22:35:51         at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
01-Nov-2018 22:35:51         at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
01-Nov-2018 22:35:51         at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.statements.RunBeforeTestExecutionCallbacks.evaluate(RunBeforeTestExecutionCallbacks.java:74)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.statements.RunAfterTestExecutionCallbacks.evaluate(RunAfterTestExecutionCallbacks.java:84)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:75)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:86)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:84)
01-Nov-2018 22:35:51         at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:251)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:97)
01-Nov-2018 22:35:51         at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
01-Nov-2018 22:35:51         at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
01-Nov-2018 22:35:51         at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
01-Nov-2018 22:35:51         at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
01-Nov-2018 22:35:51         at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:70)
01-Nov-2018 22:35:51         at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:190)
01-Nov-2018 22:35:51         at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365)
01-Nov-2018 22:35:51         at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273)
01-Nov-2018 22:35:51         at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238)
01-Nov-2018 22:35:51         at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159)
01-Nov-2018 22:35:51         at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
01-Nov-2018 22:35:51         at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
01-Nov-2018 22:35:51         at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
01-Nov-2018 22:35:51         at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
01-Nov-2018 22:35:51 Caused by: java.lang.IllegalStateException: Input resource must exist (reader is in 'strict' mode): class path resource [missing-data.csv]
01-Nov-2018 22:35:51         at org.springframework.batch.item.file.FlatFileItemReader.doOpen(FlatFileItemReader.java:251)
01-Nov-2018 22:35:51         at org.springframework.batch.item.support.AbstractItemCountingItemStreamItemReader.open(AbstractItemCountingItemStreamItemReader.java:149)
01-Nov-2018 22:35:51         ... 71 common frames omitted
01-Nov-2018 22:35:51 22:35:51.147 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.updateExecutionContext]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.147 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@1901700557 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.147 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@1901700557 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.148 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.148 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [UPDATE BATCH_STEP_EXECUTION_CONTEXT SET SHORT_CONTEXT = ?, SERIALIZED_CONTEXT = ? WHERE STEP_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.148 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.148 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@1901700557 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.149 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@1901700557 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.149 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.149 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.update]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.149 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@1335256857 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.149 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@1335256857 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.149 [main] DEBUG org.springframework.batch.core.repository.dao.JdbcStepExecutionDao - Truncating long message before update of StepExecution, original message is: org.springframework.batch.item.ItemStreamException: Failed to initialize the reader
01-Nov-2018 22:35:51         at org.springframework.batch.item.support.AbstractItemCountingItemStreamItemReader.open(AbstractItemCountingItemStreamItemReader.java:152)
01-Nov-2018 22:35:51         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
01-Nov-2018 22:35:51         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
01-Nov-2018 22:35:51         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
01-Nov-2018 22:35:51         at java.lang.reflect.Method.invoke(Method.java:498)
01-Nov-2018 22:35:51         at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343)
01-Nov-2018 22:35:51         at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
01-Nov-2018 22:35:51         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
01-Nov-2018 22:35:51         at org.springframework.aop.support.DelegatingIntroductionInterceptor.doProceed(DelegatingIntroductionInterceptor.java:136)
01-Nov-2018 22:35:51         at org.springframework.aop.support.DelegatingIntroductionInterceptor.invoke(DelegatingIntroductionInterceptor.java:124)
01-Nov-2018 22:35:51         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
01-Nov-2018 22:35:51         at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
01-Nov-2018 22:35:51         at com.sun.proxy.$Proxy53.open(Unknown Source)
01-Nov-2018 22:35:51         at org.springframework.batch.item.support.CompositeItemStream.open(CompositeItemStream.java:103)
01-Nov-2018 22:35:51         at org.springframework.batch.core.step.tasklet.TaskletStep.open(TaskletStep.java:311)
01-Nov-2018 22:35:51         at org.springframework.batch.core.step.AbstractStep.execute(AbstractStep.java:200)
01-Nov-2018 22:35:51         at org.springframework.batch.core.job.SimpleStepHandler.handleStep(SimpleStepHandler.java:148)
01-Nov-2018 22:35:51         at org.springframework.batch.core.job.flow.JobFlowExecutor.executeStep(JobFlowExecutor.java:68)
01-Nov-2018 22:35:51         at org.springframework.batch.core.job.flow.support.state.StepState.handle(StepState.java:67)
01-Nov-2018 22:35:51         at org.springframework.batch.core.job.flow.support.SimpleFlow.resume(SimpleFlow.java:169)
01-Nov-2018 22:35:51         at org.springframework.batch.core.job.flow.support.SimpleFlow.start(SimpleFlow.java:144)
01-Nov-2018 22:35:51         at org.springframework.batch.core.job.flow.FlowJob.doExecute(FlowJob.java:136)
01-Nov-2018 22:35:51         at org.springframework.batch.core.job.AbstractJob.execute(AbstractJob.java:313)
01-Nov-2018 22:35:51         at org.springframework.batch.core.launch.support.SimpleJobLauncher$1.run(SimpleJobLauncher.java:144)
01-Nov-2018 22:35:51         at org.springframework.core.task.SyncTaskExecutor.execute(SyncTaskExecutor.java:50)
01-Nov-2018 22:35:51         at org.springframework.batch.core.launch.support.SimpleJobLauncher.run(SimpleJobLauncher.java:137)
01-Nov-2018 22:35:51         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
01-Nov-2018 22:35:51         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
01-Nov-2018 22:35:51         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
01-Nov-2018 22:35:51         at java.lang.reflect.Method.invoke(Method.java:498)
01-Nov-2018 22:35:51         at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:343)
01-Nov-2018 22:35:51         at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:198)
01-Nov-2018 22:35:51         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:163)
01-Nov-2018 22:35:51         at org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration$PassthruAdvice.invoke(SimpleBatchConfiguration.java:127)
01-Nov-2018 22:35:51         at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:186)
01-Nov-2018 22:35:51         at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:212)
01-Nov-2018 22:35:51         at com.sun.proxy.$Proxy50.run(Unknown Source)
01-Nov-2018 22:35:51         at org.springframework.batch.test.JobLauncherTestUtils.launchJob(JobLauncherTestUtils.java:154)
01-Nov-2018 22:35:51         at io.spring.cloud.dataflow.ingest.BatchApplicationTests.testBatchConfigurationFail(BatchApplicationTests.java:61)
01-Nov-2018 22:35:51         at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
01-Nov-2018 22:35:51         at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
01-Nov-2018 22:35:51         at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
01-Nov-2018 22:35:51         at java.lang.reflect.Method.invoke(Method.java:498)
01-Nov-2018 22:35:51         at org.junit.runners.model.FrameworkMethod$1.runReflectiveCall(FrameworkMethod.java:50)
01-Nov-2018 22:35:51         at org.junit.internal.runners.model.ReflectiveCallable.run(ReflectiveCallable.java:12)
01-Nov-2018 22:35:51         at org.junit.runners.model.FrameworkMethod.invokeExplosively(FrameworkMethod.java:47)
01-Nov-2018 22:35:51         at org.junit.internal.runners.statements.InvokeMethod.evaluate(InvokeMethod.java:17)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.statements.RunBeforeTestExecutionCallbacks.evaluate(RunBeforeTestExecutionCallbacks.java:74)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.statements.RunAfterTestExecutionCallbacks.evaluate(RunAfterTestExecutionCallbacks.java:84)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.statements.RunBeforeTestMethodCallbacks.evaluate(RunBeforeTestMethodCallbacks.java:75)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.statements.RunAfterTestMethodCallbacks.evaluate(RunAfterTestMethodCallbacks.java:86)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.statements.SpringRepeat.evaluate(SpringRepeat.java:84)
01-Nov-2018 22:35:51         at org.junit.runners.ParentRunner.runLeaf(ParentRunner.java:325)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:251)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.runChild(SpringJUnit4ClassRunner.java:97)
01-Nov-2018 22:35:51         at org.junit.runners.ParentRunner$3.run(ParentRunner.java:290)
01-Nov-2018 22:35:51         at org.junit.runners.ParentRunner$1.schedule(ParentRunner.java:71)
01-Nov-2018 22:35:51         at org.junit.runners.ParentRunner.runChildren(ParentRunner.java:288)
01-Nov-2018 22:35:51         at org.junit.runners.ParentRunner.access$000(ParentRunner.java:58)
01-Nov-2018 22:35:51         at org.junit.runners.ParentRunner$2.evaluate(ParentRunner.java:268)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.statements.RunBeforeTestClassCallbacks.evaluate(RunBeforeTestClassCallbacks.java:61)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.statements.RunAfterTestClassCallbacks.evaluate(RunAfterTestClassCallbacks.java:70)
01-Nov-2018 22:35:51         at org.junit.runners.ParentRunner.run(ParentRunner.java:363)
01-Nov-2018 22:35:51         at org.springframework.test.context.junit4.SpringJUnit4ClassRunner.run(SpringJUnit4ClassRunner.java:190)
01-Nov-2018 22:35:51         at org.apache.maven.surefire.junit4.JUnit4Provider.execute(JUnit4Provider.java:365)
01-Nov-2018 22:35:51         at org.apache.maven.surefire.junit4.JUnit4Provider.executeWithRerun(JUnit4Provider.java:273)
01-Nov-2018 22:35:51         at org.apache.maven.surefire.junit4.JUnit4Provider.executeTestSet(JUnit4Provider.java:238)
01-Nov-2018 22:35:51         at org.apache.maven.surefire.junit4.JUnit4Provider.invoke(JUnit4Provider.java:159)
01-Nov-2018 22:35:51         at org.apache.maven.surefire.booter.ForkedBooter.invokeProviderInSameClassLoader(ForkedBooter.java:384)
01-Nov-2018 22:35:51         at org.apache.maven.surefire.booter.ForkedBooter.runSuitesInProcess(ForkedBooter.java:345)
01-Nov-2018 22:35:51         at org.apache.maven.surefire.booter.ForkedBooter.execute(ForkedBooter.java:126)
01-Nov-2018 22:35:51         at org.apache.maven.surefire.booter.ForkedBooter.main(ForkedBooter.java:418)
01-Nov-2018 22:35:51 Caused by: java.lang.IllegalStateException: Input resource must exist (reader is in 'strict' mode): class path resource [missing-data.csv]
01-Nov-2018 22:35:51         at org.springframework.batch.item.file.FlatFileItemReader.doOpen(FlatFileItemReader.java:251)
01-Nov-2018 22:35:51         at org.springframework.batch.item.support.AbstractItemCountingItemStreamItemReader.open(AbstractItemCountingItemStreamItemReader.java:149)
01-Nov-2018 22:35:51         ... 71 more
01-Nov-2018 22:35:51
01-Nov-2018 22:35:51 22:35:51.149 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.149 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [UPDATE BATCH_STEP_EXECUTION set START_TIME = ?, END_TIME = ?, STATUS = ?, COMMIT_COUNT = ?, READ_COUNT = ?, FILTER_COUNT = ?, WRITE_COUNT = ?, EXIT_CODE = ?, EXIT_MESSAGE = ?, VERSION = ?, READ_SKIP_COUNT = ?, PROCESS_SKIP_COUNT = ?, WRITE_SKIP_COUNT = ?, ROLLBACK_COUNT = ?, LAST_UPDATED = ? where STEP_EXECUTION_ID = ? and VERSION = ?]
01-Nov-2018 22:35:51 22:35:51.150 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.150 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT VERSION FROM BATCH_JOB_EXECUTION WHERE JOB_EXECUTION_ID=?]
01-Nov-2018 22:35:51 22:35:51.150 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.150 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@1335256857 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.150 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@1335256857 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.150 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.151 [main] DEBUG org.springframework.batch.core.step.AbstractStep - Step execution complete: StepExecution: id=1, version=2, name=ingest, status=FAILED, exitStatus=FAILED, readCount=0, filterCount=0, writeCount=0 readSkipCount=0, writeSkipCount=0, processSkipCount=0, commitCount=0, rollbackCount=0
01-Nov-2018 22:35:51 22:35:51.151 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.updateExecutionContext]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.151 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@413946856 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.151 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@413946856 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.151 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.151 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [UPDATE BATCH_JOB_EXECUTION_CONTEXT SET SHORT_CONTEXT = ?, SERIALIZED_CONTEXT = ? WHERE JOB_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.152 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.152 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@413946856 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.152 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@413946856 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.152 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.152 [main] DEBUG org.springframework.batch.core.job.flow.support.SimpleFlow - Completed state=ingestJob.ingest with status=FAILED
01-Nov-2018 22:35:51 22:35:51.152 [main] DEBUG org.springframework.batch.core.job.flow.support.SimpleFlow - Handling state=ingestJob.FAILED
01-Nov-2018 22:35:51 22:35:51.152 [main] DEBUG org.springframework.batch.core.job.flow.support.SimpleFlow - Completed state=ingestJob.FAILED with status=FAILED
01-Nov-2018 22:35:51 22:35:51.153 [main] DEBUG org.springframework.batch.core.job.AbstractJob - Job execution complete: JobExecution: id=1, version=1, startTime=Thu Nov 01 22:35:51 UTC 2018, endTime=null, lastUpdated=Thu Nov 01 22:35:51 UTC 2018, status=FAILED, exitStatus=exitCode=FAILED;exitDescription=, job=[JobInstance: id=1, version=0, Job=[ingestJob]], jobParameters=[{localFilePath=classpath:missing-data.csv}]
01-Nov-2018 22:35:51 22:35:51.153 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.update]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.153 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@204568533 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.153 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@204568533 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.153 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.154 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT VERSION FROM BATCH_JOB_EXECUTION WHERE JOB_EXECUTION_ID=?]
01-Nov-2018 22:35:51 22:35:51.154 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.154 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT COUNT(*) FROM BATCH_JOB_EXECUTION WHERE JOB_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.154 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.154 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [UPDATE BATCH_JOB_EXECUTION set START_TIME = ?, END_TIME = ?,  STATUS = ?, EXIT_CODE = ?, EXIT_MESSAGE = ?, VERSION = ?, CREATE_TIME = ?, LAST_UPDATED = ? where JOB_EXECUTION_ID = ? and VERSION = ?]
01-Nov-2018 22:35:51 22:35:51.155 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.155 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@204568533 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.155 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@204568533 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.155 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.155 [main] INFO org.springframework.batch.core.launch.support.SimpleJobLauncher - Job: [FlowJob: [name=ingestJob]] completed with the following parameters: [{localFilePath=classpath:missing-data.csv}] and the following status: [FAILED]
01-Nov-2018 22:35:51 22:35:51.157 [main] DEBUG org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate - Retrieved ApplicationContext from cache with key [[MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]]]
01-Nov-2018 22:35:51 22:35:51.157 [main] DEBUG org.springframework.test.context.cache - Spring test ApplicationContext cache statistics: [DefaultContextCache@64030b91 size = 1, maxSize = 32, parentContextCount = 0, hitCount = 2, missCount = 1]
01-Nov-2018 22:35:51 22:35:51.157 [main] DEBUG org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate - Retrieved ApplicationContext from cache with key [[MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]]]
01-Nov-2018 22:35:51 22:35:51.157 [main] DEBUG org.springframework.test.context.cache - Spring test ApplicationContext cache statistics: [DefaultContextCache@64030b91 size = 1, maxSize = 32, parentContextCount = 0, hitCount = 3, missCount = 1]
01-Nov-2018 22:35:51 22:35:51.159 [main] DEBUG org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate - Retrieved ApplicationContext from cache with key [[MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]]]
01-Nov-2018 22:35:51 22:35:51.159 [main] DEBUG org.springframework.test.context.cache - Spring test ApplicationContext cache statistics: [DefaultContextCache@64030b91 size = 1, maxSize = 32, parentContextCount = 0, hitCount = 4, missCount = 1]
01-Nov-2018 22:35:51 22:35:51.159 [main] DEBUG org.springframework.test.context.support.AbstractDirtiesContextTestExecutionListener - After test method: context [DefaultTestContext@453da22c testClass = BatchApplicationTests, testInstance = io.spring.cloud.dataflow.ingest.BatchApplicationTests@23a5fd2, testMethod = testBatchConfigurationFail@BatchApplicationTests, testException = [null], mergedContextConfiguration = [MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]], attributes = map[[empty]]], class annotated with @DirtiesContext [false] with mode [null], method annotated with @DirtiesContext [false] with mode [null].
01-Nov-2018 22:35:51 22:35:51.159 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved @ProfileValueSourceConfiguration [null] for test class [io.spring.cloud.dataflow.ingest.BatchApplicationTests]
01-Nov-2018 22:35:51 22:35:51.159 [main] DEBUG org.springframework.test.annotation.ProfileValueUtils - Retrieved ProfileValueSource type [class org.springframework.test.annotation.SystemProfileValueSource] for class [io.spring.cloud.dataflow.ingest.BatchApplicationTests]
01-Nov-2018 22:35:51 22:35:51.160 [main] DEBUG org.springframework.test.context.support.DependencyInjectionTestExecutionListener - Performing dependency injection for test context [[DefaultTestContext@453da22c testClass = BatchApplicationTests, testInstance = io.spring.cloud.dataflow.ingest.BatchApplicationTests@3491e86e, testMethod = [null], testException = [null], mergedContextConfiguration = [MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]], attributes = map[[empty]]]].
01-Nov-2018 22:35:51 22:35:51.160 [main] DEBUG org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate - Retrieved ApplicationContext from cache with key [[MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]]]
01-Nov-2018 22:35:51 22:35:51.160 [main] DEBUG org.springframework.test.context.cache - Spring test ApplicationContext cache statistics: [DefaultContextCache@64030b91 size = 1, maxSize = 32, parentContextCount = 0, hitCount = 5, missCount = 1]
01-Nov-2018 22:35:51 22:35:51.161 [main] DEBUG org.springframework.test.context.support.AbstractDirtiesContextTestExecutionListener - Before test method: context [DefaultTestContext@453da22c testClass = BatchApplicationTests, testInstance = io.spring.cloud.dataflow.ingest.BatchApplicationTests@3491e86e, testMethod = testBatchDataProcessing@BatchApplicationTests, testException = [null], mergedContextConfiguration = [MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]], attributes = map[[empty]]], class annotated with @DirtiesContext [false] with mode [null], method annotated with @DirtiesContext [false] with mode [null].
01-Nov-2018 22:35:51 22:35:51.161 [main] DEBUG org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate - Retrieved ApplicationContext from cache with key [[MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]]]
01-Nov-2018 22:35:51 22:35:51.161 [main] DEBUG org.springframework.test.context.cache - Spring test ApplicationContext cache statistics: [DefaultContextCache@64030b91 size = 1, maxSize = 32, parentContextCount = 0, hitCount = 6, missCount = 1]
01-Nov-2018 22:35:51 22:35:51.162 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.getLastJobExecution]: PROPAGATION_REQUIRES_NEW,ISOLATION_SERIALIZABLE
01-Nov-2018 22:35:51 22:35:51.162 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@1760763936 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.162 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Changing isolation level of JDBC Connection [HikariProxyConnection@1760763936 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to 8
01-Nov-2018 22:35:51 22:35:51.162 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@1760763936 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.163 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.163 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_INSTANCE_ID, JOB_NAME from BATCH_JOB_INSTANCE where JOB_NAME = ? and JOB_KEY = ?]
01-Nov-2018 22:35:51 22:35:51.163 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.163 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@1760763936 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.163 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Resetting isolation level of JDBC Connection [HikariProxyConnection@1760763936 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to 2
01-Nov-2018 22:35:51 22:35:51.164 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@1760763936 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.164 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.164 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.createJobExecution]: PROPAGATION_REQUIRES_NEW,ISOLATION_SERIALIZABLE
01-Nov-2018 22:35:51 22:35:51.164 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@1083803390 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.164 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Changing isolation level of JDBC Connection [HikariProxyConnection@1083803390 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to 8
01-Nov-2018 22:35:51 22:35:51.164 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@1083803390 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.165 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.165 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_INSTANCE_ID, JOB_NAME from BATCH_JOB_INSTANCE where JOB_NAME = ? and JOB_KEY = ?]
01-Nov-2018 22:35:51 22:35:51.165 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.165 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_INSTANCE_ID, JOB_NAME from BATCH_JOB_INSTANCE where JOB_NAME = ? and JOB_KEY = ?]
01-Nov-2018 22:35:51 22:35:51.166 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.166 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT into BATCH_JOB_INSTANCE(JOB_INSTANCE_ID, JOB_NAME, JOB_KEY, VERSION) values (?, ?, ?, ?)]
01-Nov-2018 22:35:51 22:35:51.167 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.167 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT into BATCH_JOB_EXECUTION(JOB_EXECUTION_ID, JOB_INSTANCE_ID, START_TIME, END_TIME, STATUS, EXIT_CODE, EXIT_MESSAGE, VERSION, CREATE_TIME, LAST_UPDATED, JOB_CONFIGURATION_LOCATION) values (?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)]
01-Nov-2018 22:35:51 22:35:51.167 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.167 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT into BATCH_JOB_EXECUTION_PARAMS(JOB_EXECUTION_ID, KEY_NAME, TYPE_CD, STRING_VAL, DATE_VAL, LONG_VAL, DOUBLE_VAL, IDENTIFYING) values (?, ?, ?, ?, ?, ?, ?, ?)]
01-Nov-2018 22:35:51 22:35:51.168 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.168 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT INTO BATCH_JOB_EXECUTION_CONTEXT (SHORT_CONTEXT, SERIALIZED_CONTEXT, JOB_EXECUTION_ID) VALUES(?, ?, ?)]
01-Nov-2018 22:35:51 22:35:51.168 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.168 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@1083803390 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.168 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Resetting isolation level of JDBC Connection [HikariProxyConnection@1083803390 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to 2
01-Nov-2018 22:35:51 22:35:51.169 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@1083803390 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.169 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.169 [main] INFO org.springframework.batch.core.launch.support.SimpleJobLauncher - Job: [FlowJob: [name=ingestJob]] launched with the following parameters: [{localFilePath=classpath:data.csv}]
01-Nov-2018 22:35:51 22:35:51.169 [main] DEBUG org.springframework.batch.core.job.AbstractJob - Job execution starting: JobExecution: id=2, version=0, startTime=null, endTime=null, lastUpdated=Thu Nov 01 22:35:51 UTC 2018, status=STARTING, exitStatus=exitCode=UNKNOWN;exitDescription=, job=[JobInstance: id=2, version=0, Job=[ingestJob]], jobParameters=[{localFilePath=classpath:data.csv}]
01-Nov-2018 22:35:51 22:35:51.169 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.update]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.170 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@430983166 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.170 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@430983166 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.170 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.170 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT VERSION FROM BATCH_JOB_EXECUTION WHERE JOB_EXECUTION_ID=?]
01-Nov-2018 22:35:51 22:35:51.170 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.170 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT COUNT(*) FROM BATCH_JOB_EXECUTION WHERE JOB_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.171 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.171 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [UPDATE BATCH_JOB_EXECUTION set START_TIME = ?, END_TIME = ?,  STATUS = ?, EXIT_CODE = ?, EXIT_MESSAGE = ?, VERSION = ?, CREATE_TIME = ?, LAST_UPDATED = ? where JOB_EXECUTION_ID = ? and VERSION = ?]
01-Nov-2018 22:35:51 22:35:51.171 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.171 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@430983166 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.171 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@430983166 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.172 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.172 [main] INFO org.springframework.cloud.task.batch.listener.TaskBatchExecutionListener - The job execution id 2 was run within the task execution 1
01-Nov-2018 22:35:51 22:35:51.172 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.172 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT INTO TASK_TASK_BATCH VALUES(?, ?)]
01-Nov-2018 22:35:51 22:35:51.172 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:51 22:35:51.172 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.172 [main] DEBUG org.springframework.batch.core.job.flow.support.SimpleFlow - Resuming state=ingestJob.ingest with status=UNKNOWN
01-Nov-2018 22:35:51 22:35:51.172 [main] DEBUG org.springframework.batch.core.job.flow.support.SimpleFlow - Handling state=ingestJob.ingest
01-Nov-2018 22:35:51 22:35:51.172 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.getStepExecutionCount]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.172 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@1406851189 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.172 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@1406851189 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.172 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.173 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_EXECUTION_ID, START_TIME, END_TIME, STATUS, EXIT_CODE, EXIT_MESSAGE, CREATE_TIME, LAST_UPDATED, VERSION, JOB_CONFIGURATION_LOCATION from BATCH_JOB_EXECUTION where JOB_INSTANCE_ID = ? order by JOB_EXECUTION_ID desc]
01-Nov-2018 22:35:51 22:35:51.173 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.173 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_EXECUTION_ID, KEY_NAME, TYPE_CD, STRING_VAL, DATE_VAL, LONG_VAL, DOUBLE_VAL, IDENTIFYING from BATCH_JOB_EXECUTION_PARAMS where JOB_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.174 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.174 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT STEP_EXECUTION_ID, STEP_NAME, START_TIME, END_TIME, STATUS, COMMIT_COUNT, READ_COUNT, FILTER_COUNT, WRITE_COUNT, EXIT_CODE, EXIT_MESSAGE, READ_SKIP_COUNT, WRITE_SKIP_COUNT, PROCESS_SKIP_COUNT, ROLLBACK_COUNT, LAST_UPDATED, VERSION from BATCH_STEP_EXECUTION where JOB_EXECUTION_ID = ? order by STEP_EXECUTION_ID]
01-Nov-2018 22:35:51 22:35:51.174 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.174 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@1406851189 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.174 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@1406851189 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.174 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.175 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.getLastStepExecution]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.175 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@1601702534 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.175 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@1601702534 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.175 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.175 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_EXECUTION_ID, START_TIME, END_TIME, STATUS, EXIT_CODE, EXIT_MESSAGE, CREATE_TIME, LAST_UPDATED, VERSION, JOB_CONFIGURATION_LOCATION from BATCH_JOB_EXECUTION where JOB_INSTANCE_ID = ? order by JOB_EXECUTION_ID desc]
01-Nov-2018 22:35:51 22:35:51.175 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.175 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_EXECUTION_ID, KEY_NAME, TYPE_CD, STRING_VAL, DATE_VAL, LONG_VAL, DOUBLE_VAL, IDENTIFYING from BATCH_JOB_EXECUTION_PARAMS where JOB_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.175 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.175 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT STEP_EXECUTION_ID, STEP_NAME, START_TIME, END_TIME, STATUS, COMMIT_COUNT, READ_COUNT, FILTER_COUNT, WRITE_COUNT, EXIT_CODE, EXIT_MESSAGE, READ_SKIP_COUNT, WRITE_SKIP_COUNT, PROCESS_SKIP_COUNT, ROLLBACK_COUNT, LAST_UPDATED, VERSION from BATCH_STEP_EXECUTION where JOB_EXECUTION_ID = ? order by STEP_EXECUTION_ID]
01-Nov-2018 22:35:51 22:35:51.175 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.176 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@1601702534 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.176 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@1601702534 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.176 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.176 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.getStepExecutionCount]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.176 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@1147943200 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.176 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@1147943200 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.176 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.176 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_EXECUTION_ID, START_TIME, END_TIME, STATUS, EXIT_CODE, EXIT_MESSAGE, CREATE_TIME, LAST_UPDATED, VERSION, JOB_CONFIGURATION_LOCATION from BATCH_JOB_EXECUTION where JOB_INSTANCE_ID = ? order by JOB_EXECUTION_ID desc]
01-Nov-2018 22:35:51 22:35:51.176 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.176 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT JOB_EXECUTION_ID, KEY_NAME, TYPE_CD, STRING_VAL, DATE_VAL, LONG_VAL, DOUBLE_VAL, IDENTIFYING from BATCH_JOB_EXECUTION_PARAMS where JOB_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.177 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.177 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT STEP_EXECUTION_ID, STEP_NAME, START_TIME, END_TIME, STATUS, COMMIT_COUNT, READ_COUNT, FILTER_COUNT, WRITE_COUNT, EXIT_CODE, EXIT_MESSAGE, READ_SKIP_COUNT, WRITE_SKIP_COUNT, PROCESS_SKIP_COUNT, ROLLBACK_COUNT, LAST_UPDATED, VERSION from BATCH_STEP_EXECUTION where JOB_EXECUTION_ID = ? order by STEP_EXECUTION_ID]
01-Nov-2018 22:35:51 22:35:51.177 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.177 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@1147943200 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.177 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@1147943200 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.177 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.177 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.add]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.177 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@724736957 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.177 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@724736957 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.178 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.178 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT into BATCH_STEP_EXECUTION(STEP_EXECUTION_ID, VERSION, STEP_NAME, JOB_EXECUTION_ID, START_TIME, END_TIME, STATUS, COMMIT_COUNT, READ_COUNT, FILTER_COUNT, WRITE_COUNT, EXIT_CODE, EXIT_MESSAGE, READ_SKIP_COUNT, WRITE_SKIP_COUNT, PROCESS_SKIP_COUNT, ROLLBACK_COUNT, LAST_UPDATED) values(?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?, ?)]
01-Nov-2018 22:35:51 22:35:51.178 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.178 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT INTO BATCH_STEP_EXECUTION_CONTEXT (SHORT_CONTEXT, SERIALIZED_CONTEXT, STEP_EXECUTION_ID) VALUES(?, ?, ?)]
01-Nov-2018 22:35:51 22:35:51.179 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.179 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@724736957 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.179 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@724736957 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.179 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.179 [main] INFO org.springframework.batch.core.job.SimpleStepHandler - Executing step: [ingest]
01-Nov-2018 22:35:51 22:35:51.179 [main] DEBUG org.springframework.batch.core.step.AbstractStep - Executing: id=2
01-Nov-2018 22:35:51 22:35:51.179 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.update]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.179 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@880908391 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.179 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@880908391 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.180 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.180 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [UPDATE BATCH_STEP_EXECUTION set START_TIME = ?, END_TIME = ?, STATUS = ?, COMMIT_COUNT = ?, READ_COUNT = ?, FILTER_COUNT = ?, WRITE_COUNT = ?, EXIT_CODE = ?, EXIT_MESSAGE = ?, VERSION = ?, READ_SKIP_COUNT = ?, PROCESS_SKIP_COUNT = ?, WRITE_SKIP_COUNT = ?, ROLLBACK_COUNT = ?, LAST_UPDATED = ? where STEP_EXECUTION_ID = ? and VERSION = ?]
01-Nov-2018 22:35:51 22:35:51.180 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.180 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT VERSION FROM BATCH_JOB_EXECUTION WHERE JOB_EXECUTION_ID=?]
01-Nov-2018 22:35:51 22:35:51.181 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.181 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@880908391 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.181 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@880908391 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.181 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.181 [main] DEBUG org.springframework.batch.core.scope.StepScope - Creating object in scope=step, name=scopedTarget.reader
01-Nov-2018 22:35:51 22:35:51.182 [main] DEBUG org.springframework.batch.core.scope.StepScope - Registered destruction callback in scope=step, name=scopedTarget.reader
01-Nov-2018 22:35:51 22:35:51.183 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.updateExecutionContext]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.183 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@1332208607 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.183 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@1332208607 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.204 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.204 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [UPDATE BATCH_STEP_EXECUTION_CONTEXT SET SHORT_CONTEXT = ?, SERIALIZED_CONTEXT = ? WHERE STEP_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.204 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.205 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@1332208607 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.205 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@1332208607 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.205 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.207 [main] DEBUG org.springframework.batch.repeat.support.RepeatTemplate - Starting repeat context.
01-Nov-2018 22:35:51 22:35:51.207 [main] DEBUG org.springframework.batch.repeat.support.RepeatTemplate - Repeat operation about to start at count=1
01-Nov-2018 22:35:51 22:35:51.208 [main] DEBUG org.springframework.batch.core.scope.context.StepContextRepeatCallback - Preparing chunk execution for StepContext: org.springframework.batch.core.scope.context.StepContext@5a00eb1e
01-Nov-2018 22:35:51 22:35:51.208 [main] DEBUG org.springframework.batch.core.scope.context.StepContextRepeatCallback - Chunk execution starting: queue size=0
01-Nov-2018 22:35:51 22:35:51.209 [main] DEBUG org.springframework.batch.core.configuration.annotation.SimpleBatchConfiguration$ReferenceTargetSource - Initializing lazy target object
01-Nov-2018 22:35:51 22:35:51.209 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [null]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.209 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@1140202235 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.209 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@1140202235 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.212 [main] DEBUG org.springframework.batch.repeat.support.RepeatTemplate - Starting repeat context.
01-Nov-2018 22:35:51 22:35:51.212 [main] DEBUG org.springframework.batch.repeat.support.RepeatTemplate - Repeat operation about to start at count=1
01-Nov-2018 22:35:51 22:35:51.212 [main] DEBUG org.springframework.batch.repeat.support.RepeatTemplate - Repeat operation about to start at count=2
01-Nov-2018 22:35:51 22:35:51.213 [main] DEBUG org.springframework.batch.repeat.support.RepeatTemplate - Repeat operation about to start at count=3
01-Nov-2018 22:35:51 22:35:51.213 [main] DEBUG org.springframework.batch.repeat.support.RepeatTemplate - Repeat operation about to start at count=4
01-Nov-2018 22:35:51 22:35:51.213 [main] DEBUG org.springframework.batch.repeat.support.RepeatTemplate - Repeat operation about to start at count=5
01-Nov-2018 22:35:51 22:35:51.213 [main] DEBUG org.springframework.batch.repeat.support.RepeatTemplate - Repeat operation about to start at count=6
01-Nov-2018 22:35:51 22:35:51.213 [main] DEBUG org.springframework.batch.repeat.support.RepeatTemplate - Repeat is complete according to policy and result value.
01-Nov-2018 22:35:51 22:35:51.214 [main] INFO io.spring.cloud.dataflow.ingest.processor.PersonItemProcessor - Processed: First name: Jill , last name: Doe into: First name: JILL , last name: DOE
01-Nov-2018 22:35:51 22:35:51.214 [main] INFO io.spring.cloud.dataflow.ingest.processor.PersonItemProcessor - Processed: First name: Joe , last name: Doe into: First name: JOE , last name: DOE
01-Nov-2018 22:35:51 22:35:51.214 [main] INFO io.spring.cloud.dataflow.ingest.processor.PersonItemProcessor - Processed: First name: Justin , last name: Doe into: First name: JUSTIN , last name: DOE
01-Nov-2018 22:35:51 22:35:51.214 [main] INFO io.spring.cloud.dataflow.ingest.processor.PersonItemProcessor - Processed: First name: Jane , last name: Doe into: First name: JANE , last name: DOE
01-Nov-2018 22:35:51 22:35:51.214 [main] INFO io.spring.cloud.dataflow.ingest.processor.PersonItemProcessor - Processed: First name: John , last name: Doe into: First name: JOHN , last name: DOE
01-Nov-2018 22:35:51 22:35:51.214 [main] DEBUG org.springframework.batch.item.database.JdbcBatchItemWriter - Executing batch with 5 items.
01-Nov-2018 22:35:51 22:35:51.217 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing SQL batch update [INSERT INTO people (first_name, last_name) VALUES (?, ?)]
01-Nov-2018 22:35:51 22:35:51.218 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [INSERT INTO people (first_name, last_name) VALUES (?, ?)]
01-Nov-2018 22:35:51 22:35:51.218 [main] DEBUG org.springframework.jdbc.support.JdbcUtils - JDBC driver supports batch updates
01-Nov-2018 22:35:51 22:35:51.222 [main] DEBUG org.springframework.batch.core.step.item.ChunkOrientedTasklet - Inputs not busy, ended: true
01-Nov-2018 22:35:51 22:35:51.223 [main] DEBUG org.springframework.batch.core.step.tasklet.TaskletStep - Applying contribution: [StepContribution: read=5, written=5, filtered=0, readSkips=0, writeSkips=0, processSkips=0, exitStatus=EXECUTING]
01-Nov-2018 22:35:51 22:35:51.223 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Participating in existing transaction
01-Nov-2018 22:35:51 22:35:51.223 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.223 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [UPDATE BATCH_STEP_EXECUTION_CONTEXT SET SHORT_CONTEXT = ?, SERIALIZED_CONTEXT = ? WHERE STEP_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.224 [main] DEBUG org.springframework.batch.core.step.tasklet.TaskletStep - Saving step execution before commit: StepExecution: id=2, version=1, name=ingest, status=STARTED, exitStatus=EXECUTING, readCount=5, filterCount=0, writeCount=5 readSkipCount=0, writeSkipCount=0, processSkipCount=0, commitCount=1, rollbackCount=0, exitDescription=
01-Nov-2018 22:35:51 22:35:51.224 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Participating in existing transaction
01-Nov-2018 22:35:51 22:35:51.224 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.224 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [UPDATE BATCH_STEP_EXECUTION set START_TIME = ?, END_TIME = ?, STATUS = ?, COMMIT_COUNT = ?, READ_COUNT = ?, FILTER_COUNT = ?, WRITE_COUNT = ?, EXIT_CODE = ?, EXIT_MESSAGE = ?, VERSION = ?, READ_SKIP_COUNT = ?, PROCESS_SKIP_COUNT = ?, WRITE_SKIP_COUNT = ?, ROLLBACK_COUNT = ?, LAST_UPDATED = ? where STEP_EXECUTION_ID = ? and VERSION = ?]
01-Nov-2018 22:35:51 22:35:51.225 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.225 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT VERSION FROM BATCH_JOB_EXECUTION WHERE JOB_EXECUTION_ID=?]
01-Nov-2018 22:35:51 22:35:51.225 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.225 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@1140202235 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.225 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@1140202235 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.225 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.225 [main] DEBUG org.springframework.batch.repeat.support.RepeatTemplate - Repeat is complete according to policy and result value.
01-Nov-2018 22:35:51 22:35:51.226 [main] DEBUG org.springframework.batch.core.step.AbstractStep - Step execution success: id=2
01-Nov-2018 22:35:51 22:35:51.226 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.updateExecutionContext]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.226 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@246745017 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.226 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@246745017 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.226 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.226 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [UPDATE BATCH_STEP_EXECUTION_CONTEXT SET SHORT_CONTEXT = ?, SERIALIZED_CONTEXT = ? WHERE STEP_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.226 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.226 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@246745017 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.227 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@246745017 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.227 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.227 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.update]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.227 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@956856274 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.227 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@956856274 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.227 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.227 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [UPDATE BATCH_STEP_EXECUTION set START_TIME = ?, END_TIME = ?, STATUS = ?, COMMIT_COUNT = ?, READ_COUNT = ?, FILTER_COUNT = ?, WRITE_COUNT = ?, EXIT_CODE = ?, EXIT_MESSAGE = ?, VERSION = ?, READ_SKIP_COUNT = ?, PROCESS_SKIP_COUNT = ?, WRITE_SKIP_COUNT = ?, ROLLBACK_COUNT = ?, LAST_UPDATED = ? where STEP_EXECUTION_ID = ? and VERSION = ?]
01-Nov-2018 22:35:51 22:35:51.227 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.227 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT VERSION FROM BATCH_JOB_EXECUTION WHERE JOB_EXECUTION_ID=?]
01-Nov-2018 22:35:51 22:35:51.228 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.228 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@956856274 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.228 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@956856274 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.228 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.228 [main] DEBUG org.springframework.batch.core.step.AbstractStep - Step execution complete: StepExecution: id=2, version=3, name=ingest, status=COMPLETED, exitStatus=COMPLETED, readCount=5, filterCount=0, writeCount=5 readSkipCount=0, writeSkipCount=0, processSkipCount=0, commitCount=1, rollbackCount=0
01-Nov-2018 22:35:51 22:35:51.228 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.updateExecutionContext]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.228 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@550707 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.228 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@550707 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.229 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.229 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [UPDATE BATCH_JOB_EXECUTION_CONTEXT SET SHORT_CONTEXT = ?, SERIALIZED_CONTEXT = ? WHERE JOB_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.229 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.229 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@550707 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.229 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@550707 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.229 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.229 [main] DEBUG org.springframework.batch.core.job.flow.support.SimpleFlow - Completed state=ingestJob.ingest with status=COMPLETED
01-Nov-2018 22:35:51 22:35:51.229 [main] DEBUG org.springframework.batch.core.job.flow.support.SimpleFlow - Handling state=ingestJob.COMPLETED
01-Nov-2018 22:35:51 22:35:51.229 [main] DEBUG org.springframework.batch.core.job.flow.support.SimpleFlow - Completed state=ingestJob.COMPLETED with status=COMPLETED
01-Nov-2018 22:35:51 22:35:51.230 [main] DEBUG org.springframework.batch.core.job.AbstractJob - Job execution complete: JobExecution: id=2, version=1, startTime=Thu Nov 01 22:35:51 UTC 2018, endTime=null, lastUpdated=Thu Nov 01 22:35:51 UTC 2018, status=COMPLETED, exitStatus=exitCode=COMPLETED;exitDescription=, job=[JobInstance: id=2, version=0, Job=[ingestJob]], jobParameters=[{localFilePath=classpath:data.csv}]
01-Nov-2018 22:35:51 22:35:51.230 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Creating new transaction with name [org.springframework.batch.core.repository.support.SimpleJobRepository.update]: PROPAGATION_REQUIRED,ISOLATION_DEFAULT
01-Nov-2018 22:35:51 22:35:51.230 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Acquired Connection [HikariProxyConnection@409778321 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] for JDBC transaction
01-Nov-2018 22:35:51 22:35:51.230 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Switching JDBC Connection [HikariProxyConnection@409778321 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] to manual commit
01-Nov-2018 22:35:51 22:35:51.230 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.230 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT VERSION FROM BATCH_JOB_EXECUTION WHERE JOB_EXECUTION_ID=?]
01-Nov-2018 22:35:51 22:35:51.230 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.230 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT COUNT(*) FROM BATCH_JOB_EXECUTION WHERE JOB_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.231 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.231 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [UPDATE BATCH_JOB_EXECUTION set START_TIME = ?, END_TIME = ?,  STATUS = ?, EXIT_CODE = ?, EXIT_MESSAGE = ?, VERSION = ?, CREATE_TIME = ?, LAST_UPDATED = ? where JOB_EXECUTION_ID = ? and VERSION = ?]
01-Nov-2018 22:35:51 22:35:51.232 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Initiating transaction commit
01-Nov-2018 22:35:51 22:35:51.232 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Committing JDBC transaction on Connection [HikariProxyConnection@409778321 wrapping conn0: url=jdbc:h2:mem:testdb user=SA]
01-Nov-2018 22:35:51 22:35:51.232 [main] DEBUG org.springframework.jdbc.datasource.DataSourceTransactionManager - Releasing JDBC Connection [HikariProxyConnection@409778321 wrapping conn0: url=jdbc:h2:mem:testdb user=SA] after transaction
01-Nov-2018 22:35:51 22:35:51.232 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.232 [main] INFO org.springframework.batch.core.launch.support.SimpleJobLauncher - Job: [FlowJob: [name=ingestJob]] completed with the following parameters: [{localFilePath=classpath:data.csv}] and the following status: [COMPLETED]
01-Nov-2018 22:35:51 22:35:51.232 [main] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing SQL query [select first_name, last_name from people]
01-Nov-2018 22:35:51 22:35:51.233 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:51 22:35:51.235 [main] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.235 [main] DEBUG org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate - Retrieved ApplicationContext from cache with key [[MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]]]
01-Nov-2018 22:35:51 22:35:51.236 [main] DEBUG org.springframework.test.context.cache - Spring test ApplicationContext cache statistics: [DefaultContextCache@64030b91 size = 1, maxSize = 32, parentContextCount = 0, hitCount = 7, missCount = 1]
01-Nov-2018 22:35:51 22:35:51.236 [main] DEBUG org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate - Retrieved ApplicationContext from cache with key [[MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]]]
01-Nov-2018 22:35:51 22:35:51.236 [main] DEBUG org.springframework.test.context.cache - Spring test ApplicationContext cache statistics: [DefaultContextCache@64030b91 size = 1, maxSize = 32, parentContextCount = 0, hitCount = 8, missCount = 1]
01-Nov-2018 22:35:51 22:35:51.237 [main] DEBUG org.springframework.test.context.cache.DefaultCacheAwareContextLoaderDelegate - Retrieved ApplicationContext from cache with key [[MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]]]
01-Nov-2018 22:35:51 22:35:51.237 [main] DEBUG org.springframework.test.context.cache - Spring test ApplicationContext cache statistics: [DefaultContextCache@64030b91 size = 1, maxSize = 32, parentContextCount = 0, hitCount = 9, missCount = 1]
01-Nov-2018 22:35:51 22:35:51.237 [main] DEBUG org.springframework.test.context.support.AbstractDirtiesContextTestExecutionListener - After test method: context [DefaultTestContext@453da22c testClass = BatchApplicationTests, testInstance = io.spring.cloud.dataflow.ingest.BatchApplicationTests@3491e86e, testMethod = testBatchDataProcessing@BatchApplicationTests, testException = [null], mergedContextConfiguration = [MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]], attributes = map[[empty]]], class annotated with @DirtiesContext [false] with mode [null], method annotated with @DirtiesContext [false] with mode [null].
01-Nov-2018 22:35:51 22:35:51.238 [main] DEBUG org.springframework.test.context.support.AbstractDirtiesContextTestExecutionListener - After test class: context [DefaultTestContext@453da22c testClass = BatchApplicationTests, testInstance = [null], testMethod = [null], testException = [null], mergedContextConfiguration = [MergedContextConfiguration@71248c21 testClass = BatchApplicationTests, locations = '{}', classes = '{class io.spring.cloud.dataflow.ingest.config.BatchConfiguration, class io.spring.cloud.dataflow.ingest.BatchApplicationTests$BatchTestConfiguration}', contextInitializerClasses = '[]', activeProfiles = '{}', propertySourceLocations = '{}', propertySourceProperties = '{}', contextCustomizers = set[org.springframework.boot.test.context.filter.ExcludeFilterContextCustomizer@2e3fc542, org.springframework.boot.test.json.DuplicateJsonObjectContextCustomizerFactory$DuplicateJsonObjectContextCustomizer@401e7803, org.springframework.boot.test.mock.mockito.MockitoContextCustomizer@0, org.springframework.boot.test.autoconfigure.properties.PropertyMappingContextCustomizer@0, org.springframework.boot.test.autoconfigure.web.servlet.WebDriverContextCustomizerFactory$Customizer@35a50a4c], contextLoader = 'org.springframework.test.context.support.DelegatingSmartContextLoader', parent = [null]], attributes = map[[empty]]], class annotated with @DirtiesContext [false] with mode [null].
01-Nov-2018 22:35:51 [INFO] Tests run: 2, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 3.395 s - in io.spring.cloud.dataflow.ingest.BatchApplicationTests
01-Nov-2018 22:35:51 [INFO] Running io.spring.cloud.dataflow.ingest.processor.PersonItemProcessorTests
01-Nov-2018 22:35:51 22:35:51.238 [main] INFO io.spring.cloud.dataflow.ingest.processor.PersonItemProcessor - Processed: First name: jane , last name: doe into: First name: JANE , last name: DOE
01-Nov-2018 22:35:51 [INFO] Tests run: 1, Failures: 0, Errors: 0, Skipped: 0, Time elapsed: 0.001 s - in io.spring.cloud.dataflow.ingest.processor.PersonItemProcessorTests
01-Nov-2018 22:35:51 22:35:51.251 [Thread-2] DEBUG org.springframework.context.support.GenericApplicationContext - Closing org.springframework.context.support.GenericApplicationContext@770c2e6b, started on Thu Nov 01 22:35:48 UTC 2018
01-Nov-2018 22:35:51 22:35:51.264 [Thread-2] DEBUG org.springframework.context.support.DefaultLifecycleProcessor - Stopping beans in phase 0
01-Nov-2018 22:35:51 22:35:51.265 [Thread-2] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.265 [Thread-2] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT COUNT(*) FROM TASK_EXECUTION WHERE TASK_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.265 [Thread-2] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:51 22:35:51.266 [Thread-2] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.266 [Thread-2] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL update
01-Nov-2018 22:35:51 22:35:51.267 [Thread-2] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [UPDATE TASK_EXECUTION set END_TIME = ?, EXIT_CODE = ?, EXIT_MESSAGE = ?, ERROR_MESSAGE = ?, LAST_UPDATED = ? where TASK_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.267 [Thread-2] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:51 22:35:51.267 [Thread-2] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.267 [Thread-2] DEBUG org.springframework.cloud.task.repository.support.SimpleTaskRepository - Updating: TaskExecution with executionId=1 with the following {exitCode=0, endTime=Thu Nov 01 22:35:51 UTC 2018, exitMessage='null', errorMessage='null'}
01-Nov-2018 22:35:51 22:35:51.268 [Thread-2] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.268 [Thread-2] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT TASK_EXECUTION_ID, START_TIME, END_TIME, TASK_NAME, EXIT_CODE, EXIT_MESSAGE, ERROR_MESSAGE, LAST_UPDATED, EXTERNAL_EXECUTION_ID, PARENT_EXECUTION_ID from TASK_EXECUTION where TASK_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.268 [Thread-2] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:51 22:35:51.270 [Thread-2] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.270 [Thread-2] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT TASK_EXECUTION_ID, TASK_PARAM from TASK_EXECUTION_PARAMS where TASK_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.270 [Thread-2] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:51 22:35:51.270 [Thread-2] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.270 [Thread-2] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.270 [Thread-2] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL query
01-Nov-2018 22:35:51 22:35:51.270 [Thread-2] DEBUG org.springframework.jdbc.core.JdbcTemplate - Executing prepared SQL statement [SELECT TASK_EXECUTION_ID, TASK_PARAM from TASK_EXECUTION_PARAMS where TASK_EXECUTION_ID = ?]
01-Nov-2018 22:35:51 22:35:51.270 [Thread-2] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Fetching JDBC Connection from DataSource
01-Nov-2018 22:35:51 22:35:51.271 [Thread-2] DEBUG org.springframework.jdbc.datasource.DataSourceUtils - Returning JDBC Connection to DataSource
01-Nov-2018 22:35:51 22:35:51.271 [Thread-2] DEBUG org.springframework.context.support.DefaultLifecycleProcessor - Bean 'taskLifecycleListener' completed its stop procedure
01-Nov-2018 22:35:51 22:35:51.271 [Thread-2] DEBUG org.springframework.jmx.export.annotation.AnnotationMBeanExporter - Unregistering JMX-exposed beans on shutdown
01-Nov-2018 22:35:51 22:35:51.272 [Thread-2] DEBUG org.springframework.jmx.export.annotation.AnnotationMBeanExporter - Unregistering JMX-exposed beans
01-Nov-2018 22:35:51 22:35:51.272 [Thread-2] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown initiated...
01-Nov-2018 22:35:51 22:35:51.273 [Thread-2] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - Before shutdown stats (total=10, active=0, idle=10, waiting=0)
01-Nov-2018 22:35:51 22:35:51.274 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Closing connection conn0: url=jdbc:h2:mem:testdb user=SA: (connection evicted)
01-Nov-2018 22:35:51 22:35:51.274 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Closing connection conn1: url=jdbc:h2:mem:testdb user=SA: (connection evicted)
01-Nov-2018 22:35:51 22:35:51.274 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Closing connection conn2: url=jdbc:h2:mem:testdb user=SA: (connection evicted)
01-Nov-2018 22:35:51 22:35:51.274 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Closing connection conn3: url=jdbc:h2:mem:testdb user=SA: (connection evicted)
01-Nov-2018 22:35:51 22:35:51.274 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Closing connection conn4: url=jdbc:h2:mem:testdb user=SA: (connection evicted)
01-Nov-2018 22:35:51 22:35:51.274 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Closing connection conn5: url=jdbc:h2:mem:testdb user=SA: (connection evicted)
01-Nov-2018 22:35:51 22:35:51.274 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Closing connection conn6: url=jdbc:h2:mem:testdb user=SA: (connection evicted)
01-Nov-2018 22:35:51 22:35:51.276 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Closing connection conn7: url=jdbc:h2:mem:testdb user=SA: (connection evicted)
01-Nov-2018 22:35:51 22:35:51.276 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Closing connection conn8: url=jdbc:h2:mem:testdb user=SA: (connection evicted)
01-Nov-2018 22:35:51 22:35:51.276 [HikariPool-1 connection closer] DEBUG com.zaxxer.hikari.pool.PoolBase - HikariPool-1 - Closing connection conn9: url=jdbc:h2:mem:testdb user=SA: (connection evicted)
01-Nov-2018 22:35:51 22:35:51.276 [Thread-2] DEBUG com.zaxxer.hikari.pool.HikariPool - HikariPool-1 - After shutdown stats (total=0, active=0, idle=0, waiting=0)
01-Nov-2018 22:35:51 22:35:51.276 [Thread-2] INFO com.zaxxer.hikari.HikariDataSource - HikariPool-1 - Shutdown completed.
01-Nov-2018 22:35:51 [INFO]
01-Nov-2018 22:35:51 [INFO] Results:
01-Nov-2018 22:35:51 [INFO]
01-Nov-2018 22:35:51 [INFO] Tests run: 4, Failures: 0, Errors: 0, Skipped: 0
01-Nov-2018 22:35:51 [INFO]
01-Nov-2018 22:35:51 [INFO]
01-Nov-2018 22:35:51 [INFO] --- maven-jar-plugin:3.1.0:jar (default-jar) @ ingest ---
01-Nov-2018 22:35:52 [INFO] Building jar: /opt/bamboo-home/xml-data/build-dir/SCD-FILEINGEST-BSCDL/batch/file-ingest/target/ingest-1.0.0.BUILD-SNAPSHOT.jar
01-Nov-2018 22:35:52 [INFO]
01-Nov-2018 22:35:52 [INFO] --- spring-boot-maven-plugin:2.1.0.BUILD-SNAPSHOT:repackage (repackage) @ ingest ---
01-Nov-2018 22:35:52 Downloading: https://repo.spring.io/snapshot/org/springframework/boot/spring-boot-loader-tools/2.1.0.BUILD-SNAPSHOT/maven-metadata.xml
01-Nov-2018 22:35:52 Downloaded: https://repo.spring.io/snapshot/org/springframework/boot/spring-boot-loader-tools/2.1.0.BUILD-SNAPSHOT/maven-metadata.xml (2 KB at 4.7 KB/sec)
01-Nov-2018 22:35:52 Downloading: https://repo.spring.io/snapshot/org/springframework/boot/spring-boot-loader-tools/2.1.0.BUILD-SNAPSHOT/spring-boot-loader-tools-2.1.0.BUILD-20181030.064019-620.pom
01-Nov-2018 22:35:52 Downloaded: https://repo.spring.io/snapshot/org/springframework/boot/spring-boot-loader-tools/2.1.0.BUILD-SNAPSHOT/spring-boot-loader-tools-2.1.0.BUILD-20181030.064019-620.pom (3 KB at 13.7 KB/sec)
01-Nov-2018 22:35:52 Downloading: https://repo.spring.io/milestone/org/apache/commons/commons-lang3/3.8.1/commons-lang3-3.8.1.pom
01-Nov-2018 22:35:52 Downloading: https://repo.spring.io/snapshot/org/apache/commons/commons-lang3/3.8.1/commons-lang3-3.8.1.pom
01-Nov-2018 22:35:52 Downloading: http://repo.maven.apache.org/maven2/org/apache/commons/commons-lang3/3.8.1/commons-lang3-3.8.1.pom
01-Nov-2018 22:35:52 Downloaded: http://repo.maven.apache.org/maven2/org/apache/commons/commons-lang3/3.8.1/commons-lang3-3.8.1.pom (28 KB at 1237.9 KB/sec)
01-Nov-2018 22:35:53 Downloading: https://repo.spring.io/snapshot/org/springframework/boot/spring-boot-loader-tools/2.1.0.BUILD-SNAPSHOT/spring-boot-loader-tools-2.1.0.BUILD-20181030.064019-620.jar
01-Nov-2018 22:35:53 Downloaded: https://repo.spring.io/snapshot/org/springframework/boot/spring-boot-loader-tools/2.1.0.BUILD-SNAPSHOT/spring-boot-loader-tools-2.1.0.BUILD-20181030.064019-620.jar (145 KB at 423.5 KB/sec)
01-Nov-2018 22:35:53 Downloading: https://repo.spring.io/milestone/org/apache/commons/commons-lang3/3.8.1/commons-lang3-3.8.1.jar
01-Nov-2018 22:35:53 Downloading: https://repo.spring.io/snapshot/org/apache/commons/commons-lang3/3.8.1/commons-lang3-3.8.1.jar
01-Nov-2018 22:35:53 Downloading: http://repo.maven.apache.org/maven2/org/apache/commons/commons-lang3/3.8.1/commons-lang3-3.8.1.jar
01-Nov-2018 22:35:53 Downloaded: http://repo.maven.apache.org/maven2/org/apache/commons/commons-lang3/3.8.1/commons-lang3-3.8.1.jar (491 KB at 10428.0 KB/sec)
01-Nov-2018 22:35:54 SLF4J: Failed to load class "org.slf4j.impl.StaticLoggerBinder".
01-Nov-2018 22:35:54 SLF4J: Defaulting to no-operation (NOP) logger implementation
01-Nov-2018 22:35:54 SLF4J: See http://www.slf4j.org/codes.html#StaticLoggerBinder for further details.
01-Nov-2018 22:35:54 [INFO] Replacing main artifact /opt/bamboo-home/xml-data/build-dir/SCD-FILEINGEST-BSCDL/batch/file-ingest/target/ingest-1.0.0.BUILD-SNAPSHOT.jar
01-Nov-2018 22:35:54 [INFO]
01-Nov-2018 22:35:54 [INFO] --- maven-install-plugin:2.5.2:install (default-install) @ ingest ---
01-Nov-2018 22:35:54 [INFO] Installing /opt/bamboo-home/xml-data/build-dir/SCD-FILEINGEST-BSCDL/batch/file-ingest/target/ingest-1.0.0.BUILD-SNAPSHOT.jar to /home/bamboo/.m2/repository/io/spring/cloud/dataflow/ingest/ingest/1.0.0.BUILD-SNAPSHOT/ingest-1.0.0.BUILD-SNAPSHOT.jar
01-Nov-2018 22:35:54 [INFO] Installing /opt/bamboo-home/xml-data/build-dir/SCD-FILEINGEST-BSCDL/batch/file-ingest/pom.xml to /home/bamboo/.m2/repository/io/spring/cloud/dataflow/ingest/ingest/1.0.0.BUILD-SNAPSHOT/ingest-1.0.0.BUILD-SNAPSHOT.pom
01-Nov-2018 22:35:54 [INFO] Artifactory Build Info Recorder: Saving Build Info to '/opt/bamboo-home/xml-data/build-dir/SCD-FILEINGEST-BSCDL/batch/file-ingest/target/build-info.json'
01-Nov-2018 22:35:55 [INFO] Deploying artifact: https://repo.spring.io/libs-snapshot-local/io/spring/cloud/dataflow/ingest/ingest/1.0.0.BUILD-SNAPSHOT/ingest-1.0.0.BUILD-SNAPSHOT.jar
01-Nov-2018 22:35:56 [INFO] Deploying artifact: https://repo.spring.io/libs-snapshot-local/io/spring/cloud/dataflow/ingest/ingest/1.0.0.BUILD-SNAPSHOT/ingest-1.0.0.BUILD-SNAPSHOT.pom
01-Nov-2018 22:35:57 [INFO] Artifactory Build Info Recorder: Deploying build info ...
01-Nov-2018 22:35:57 [INFO] Deploying build descriptor to: https://repo.spring.io/api/build
01-Nov-2018 22:35:57 [INFO] Build successfully deployed. Browse it in Artifactory under https://repo.spring.io/webapp/builds/Spring%20Cloud%20Data%20Flow%20-%20Spring%20Cloud%20Data%20Flow%20Samples%20-%20File%20Ingest%20-%20Build%20File%20Ingest/9
01-Nov-2018 22:35:57 [INFO] ------------------------------------------------------------------------
01-Nov-2018 22:35:57 [INFO] BUILD SUCCESS
01-Nov-2018 22:35:57 [INFO] ------------------------------------------------------------------------
01-Nov-2018 22:35:57 [INFO] Total time: 23.188s
01-Nov-2018 22:35:57 [INFO] Finished at: Thu Nov 01 22:35:57 UTC 2018
01-Nov-2018 22:35:58 [INFO] Final Memory: 41M/547M
01-Nov-2018 22:35:58 [INFO] ------------------------------------------------------------------------
01-Nov-2018 22:35:58 [WARNING] The requested profile "full" could not be activated because it does not exist.
01-Nov-2018 22:35:58 Parsing test results under /opt/bamboo-home/xml-data/build-dir/SCD-FILEINGEST-BSCDL...
01-Nov-2018 22:35:58 Finished task 'Build and publish Spring Cloud Data Flow Sample - File Ingest' with result: Success
01-Nov-2018 22:35:58 Running post build plugin 'Docker Container Cleanup'
01-Nov-2018 22:35:58 Running post build plugin 'NCover Results Collector'
01-Nov-2018 22:35:58 Running post build plugin 'Artifactory Release Management Staging'
01-Nov-2018 22:35:58 Running post build plugin 'Artifactory Build Info Copier'
01-Nov-2018 22:35:58 Copying the buildinfo artifacts for build: SCD-FILEINGEST-BSCDL-9
01-Nov-2018 22:35:58 Running post build plugin 'Artifactory Gradle Properties Info Copier'
01-Nov-2018 22:35:58 Running post build plugin 'Clover Results Collector'
01-Nov-2018 22:35:58 Running post build plugin 'npm Cache Cleanup'
01-Nov-2018 22:35:58 Running post build plugin 'Artifact Copier'
01-Nov-2018 22:35:58 Publishing an artifact: Test Results
01-Nov-2018 22:35:58 Finished publishing of artifact Job artifact: [Test Results], pattern: [**/target/surefire-reports/**/*.*] in 32.51 ms
01-Nov-2018 22:35:58 Successfully removed working directory at '/opt/bamboo-home/xml-data/build-dir/SCD-FILEINGEST-BSCDL'
01-Nov-2018 22:35:58 Finalising the build...
01-Nov-2018 22:35:58 Stopping timer.
01-Nov-2018 22:35:58 Build SCD-FILEINGEST-BSCDL-9 completed.
01-Nov-2018 22:35:58 Running on server: post build plugin 'NCover Results Collector'
01-Nov-2018 22:35:58 Running on server: post build plugin 'Build Hanging Detection Configuration'
01-Nov-2018 22:35:58 Running on server: post build plugin 'Clover Delta Calculator'
01-Nov-2018 22:35:58 Running on server: post build plugin 'Maven Dependencies Postprocessor'
01-Nov-2018 22:35:58 All post build plugins have finished
01-Nov-2018 22:35:58 Generating build results summary...
01-Nov-2018 22:35:58 Saving build results to disk...
01-Nov-2018 22:35:58 Logging substituted variables...
01-Nov-2018 22:35:58 Indexing build results...
01-Nov-2018 22:35:58 Finished building SCD-FILEINGEST-BSCDL-9.