Merge pull request #6748 from corda/INFRA-683-os-45-bouncy-castle

NOTICK Merge OS 4.4 to 4.5

build.gradle

@@ -68,8 +68,8 @@ buildscript {
     ext.jersey_version = '2.25'
     ext.servlet_version = '4.0.1'
     ext.assertj_version = '3.12.2'
-    ext.slf4j_version = '1.7.26'
-    ext.log4j_version = '2.11.2'
+    ext.slf4j_version = '1.7.30'
+    ext.log4j_version = '2.12.1'
     ext.bouncycastle_version = constants.getProperty("bouncycastleVersion")
     ext.guava_version = constants.getProperty("guavaVersion")
     ext.caffeine_version = constants.getProperty("caffeineVersion")

common/logging/src/main/kotlin/net/corda/common/logging/ErrorCodeRewritePolicy.kt

@@ -1,28 +0,0 @@
-package net.corda.common.logging
-
-import org.apache.logging.log4j.core.Core
-import org.apache.logging.log4j.core.LogEvent
-import org.apache.logging.log4j.core.appender.rewrite.RewritePolicy
-import org.apache.logging.log4j.core.config.plugins.Plugin
-import org.apache.logging.log4j.core.config.plugins.PluginFactory
-import org.apache.logging.log4j.core.impl.Log4jLogEvent
-
-@Plugin(name = "ErrorCodeRewritePolicy", category = Core.CATEGORY_NAME, elementType = "rewritePolicy", printObject = false)
-class ErrorCodeRewritePolicy : RewritePolicy {
-    override fun rewrite(source: LogEvent): LogEvent? {
-        val newMessage = source.message?.withErrorCodeFor(source.thrown, source.level)
-        return if (newMessage == source.message) {
-            source
-        } else {
-            Log4jLogEvent.Builder(source).setMessage(newMessage).build()
-        }
-    }
-
-    companion object {
-        @JvmStatic
-        @PluginFactory
-        fun createPolicy(): ErrorCodeRewritePolicy {
-            return ErrorCodeRewritePolicy()
-        }
-    }
-}

config/dev/log4j2.xml

@@ -1,5 +1,5 @@
 <?xml version="1.0" encoding="UTF-8"?>
-<Configuration status="info" packages="net.corda.common.logging" shutdownHook="disable">
+<Configuration status="info" shutdownHook="disable">
 
     <Properties>
         <Property name="log-path">${sys:log-path:-logs}</Property>
@@ -172,21 +172,17 @@
 
         <Rewrite name="Console-ErrorCode-Selector">
             <AppenderRef ref="Console-Selector"/>
-            <ErrorCodeRewritePolicy/>
         </Rewrite>
 
         <Rewrite name="Console-ErrorCode-Appender-Println">
             <AppenderRef ref="Console-Appender-Println"/>
-            <ErrorCodeRewritePolicy/>
         </Rewrite>
 
         <Rewrite name="RollingFile-ErrorCode-Appender">
             <AppenderRef ref="RollingFile-Appender"/>
-            <ErrorCodeRewritePolicy/>
         </Rewrite>
         <Rewrite name="Diagnostic-RollingFile-ErrorCode-Appender">
             <AppenderRef ref="Diagnostic-RollingFile-Appender"/>
-            <ErrorCodeRewritePolicy/>
         </Rewrite>
     </Appenders>
 

constants.properties

@@ -20,7 +20,7 @@ quasarClassifier=jdk8
 quasarVersion11=0.8.0_r3
 jdkClassifier11=jdk11
 proguardVersion=6.1.1
-bouncycastleVersion=1.61
+bouncycastleVersion=1.66
 classgraphVersion=4.8.90
 disruptorVersion=3.4.2
 typesafeConfigVersion=1.3.4

node/src/integration-test/kotlin/net/corda/node/AuthDBTests.kt

@@ -22,9 +22,9 @@ import org.junit.Before
 import org.junit.Test
 import org.junit.runner.RunWith
 import org.junit.runners.Parameterized
+import java.sql.Connection
 import java.sql.Statement
 import java.util.*
-import javax.sql.DataSource
 import kotlin.test.assertFailsWith
 
 /*
@@ -33,7 +33,7 @@ import kotlin.test.assertFailsWith
  */
 @RunWith(Parameterized::class)
 class AuthDBTests : NodeBasedTest() {
-    private lateinit var node: NodeWithInfo
+    private var node: NodeWithInfo? = null
     private lateinit var client: CordaRPCClient
     private lateinit var db: UsersDB
 
@@ -93,8 +93,9 @@ class AuthDBTests : NodeBasedTest() {
                 )
         )
 
-        node = startNode(ALICE_NAME, rpcUsers = emptyList(), configOverrides = securityConfig)
-        client = CordaRPCClient(node.node.configuration.rpcOptions.address)
+        node = startNode(ALICE_NAME, rpcUsers = emptyList(), configOverrides = securityConfig).also { node ->
+            client = CordaRPCClient(node.node.configuration.rpcOptions.address)
+        }
     }
 
     @Test(timeout=300_000)
@@ -215,6 +216,7 @@ class AuthDBTests : NodeBasedTest() {
 
     @After
     fun tearDown() {
+        node?.node?.stop()
         db.close()
     }
 
@@ -228,7 +230,7 @@ private data class RoleAndPermissions(val role: String, val permissions: List<St
  * Manage in-memory DB mocking a users database with the schema expected by Node's security manager
  */
 private class UsersDB(name: String, users: List<UserAndRoles> = emptyList(), roleAndPermissions: List<RoleAndPermissions> = emptyList()) : AutoCloseable {
-    val jdbcUrl = "jdbc:h2:mem:$name;DB_CLOSE_DELAY=-1"
+    val jdbcUrl = "jdbc:h2:mem:$name"
 
     companion object {
         const val DB_CREATE_SCHEMA = """
@@ -269,36 +271,34 @@ private class UsersDB(name: String, users: List<UserAndRoles> = emptyList(), rol
         }
     }
 
-    private val dataSource: DataSource
+    private val connection: Connection
     private inline fun session(statement: (Statement) -> Unit) {
-        dataSource.connection.use {
-            it.autoCommit = false
-            it.createStatement().use(statement)
-            it.commit()
-        }
+        connection.createStatement().use(statement)
+        connection.commit()
     }
 
     init {
-        dataSource = DataSourceFactory.createDataSource(Properties().apply {
+        require(users.map { it.username }.toSet().size == users.size) {
+            "Duplicate username in input"
+        }
+        connection = DataSourceFactory.createDataSource(Properties().apply {
             put("dataSourceClassName", "org.h2.jdbcx.JdbcDataSource")
             put("dataSource.url", jdbcUrl)
         }, false)
+                .connection
+                .apply {
+                    autoCommit = false
+                }
         session {
             it.execute(DB_CREATE_SCHEMA)
         }
-        require(users.map { it.username }.toSet().size == users.size) {
-            "Duplicate username in input"
-        }
         users.forEach { insert(it) }
         roleAndPermissions.forEach { insert(it) }
     }
 
     override fun close() {
-        dataSource.connection.use {
-            it.createStatement().use {
-                it.execute("DROP ALL OBJECTS")
-            }
-        }
+        // Close the connection, at which point the database will shut down
+        connection.close()
     }
 }
 

node/src/integration-test/kotlin/net/corda/node/NodeConfigParsingTests.kt

@@ -1,17 +1,21 @@
 package net.corda.node
 
+import net.corda.core.internal.div
 import net.corda.core.utilities.getOrThrow
-import net.corda.node.logging.logFile
 import net.corda.testing.driver.DriverParameters
+import net.corda.testing.driver.NodeHandle
 import net.corda.testing.driver.NodeParameters
 import net.corda.testing.driver.driver
 import net.corda.testing.driver.internal.incrementalPortAllocation
 import org.assertj.core.api.Assertions.assertThatThrownBy
 import org.junit.Test
 import org.junit.Assert.assertTrue
-
+import java.io.File
 
 class NodeConfigParsingTests {
+    companion object {
+       fun NodeHandle.logFile(): File = (baseDirectory / "logs").toFile().walk().filter { it.name.startsWith("node-") && it.extension == "log" }.single()
+    }
 
     @Test(timeout=300_000)
 	fun `config is overriden by underscore variable`() {

node/src/integration-test/kotlin/net/corda/node/logging/ErrorCodeLoggingTests.kt

@@ -1,68 +0,0 @@
-package net.corda.node.logging
-
-import net.corda.core.flows.FlowLogic
-import net.corda.core.flows.InitiatingFlow
-import net.corda.core.flows.StartableByRPC
-import net.corda.core.internal.div
-import net.corda.core.messaging.FlowHandle
-import net.corda.core.messaging.startFlow
-import net.corda.core.utilities.getOrThrow
-import net.corda.testing.driver.DriverParameters
-import net.corda.testing.driver.NodeHandle
-import net.corda.testing.driver.driver
-import org.assertj.core.api.Assertions.assertThat
-import org.junit.Test
-import java.io.File
-
-class ErrorCodeLoggingTests {
-    @Test(timeout=300_000)
-	fun `log entries with a throwable and ERROR or WARN get an error code appended`() {
-        driver(DriverParameters(notarySpecs = emptyList())) {
-            val node = startNode(startInSameProcess = false).getOrThrow()
-            node.rpc.startFlow(::MyFlow).waitForCompletion()
-            val logFile = node.logFile()
-
-            val linesWithErrorCode = logFile.useLines { lines ->
-                lines.filter { line ->
-                    line.contains("[errorCode=")
-                }.filter { line ->
-                    line.contains("moreInformationAt=https://errors.corda.net/")
-                }.toList()
-            }
-
-            assertThat(linesWithErrorCode).isNotEmpty
-        }
-    }
-
-    // This is used to detect broken logging which can be caused by loggers being initialized
-    // before the initLogging() call is made
-    @Test(timeout=300_000)
-	fun `When logging is set to error level, there are no other levels logged after node startup`() {
-        driver(DriverParameters(notarySpecs = emptyList())) {
-            val node = startNode(startInSameProcess = false, logLevelOverride = "ERROR").getOrThrow()
-            val logFile = node.logFile()
-            val lengthAfterStart = logFile.length()
-            node.rpc.startFlow(::MyFlow).waitForCompletion()
-            // An exception thrown in a flow will log at the "INFO" level.
-            assertThat(logFile.length()).isEqualTo(lengthAfterStart)
-        }
-    }
-
-    @StartableByRPC
-    @InitiatingFlow
-    class MyFlow : FlowLogic<String>() {
-        override fun call(): String {
-            throw IllegalArgumentException("Mwahahahah")
-        }
-    }
-}
-
-private fun FlowHandle<*>.waitForCompletion() {
-    try {
-        returnValue.getOrThrow()
-    } catch (e: Exception) {
-        // This is expected to throw an exception, using getOrThrow() just to wait until done.
-    }
-}
-
-fun NodeHandle.logFile(): File = (baseDirectory / "logs").toFile().walk().filter { it.name.startsWith("node-") && it.extension == "log" }.single()

node/src/integration-test/kotlin/net/corda/node/services/statemachine/LargeTransactionsTest.kt

@@ -22,6 +22,7 @@ import net.corda.testing.driver.driver
 import net.corda.testing.node.User
 import net.corda.testing.node.internal.DUMMY_CONTRACTS_CORDAPP
 import net.corda.testing.node.internal.enclosedCordapp
+import org.junit.Ignore
 import org.junit.Test
 import kotlin.test.assertEquals
 
@@ -29,6 +30,7 @@ import kotlin.test.assertEquals
  * Check that we can add lots of large attachments to a transaction and that it works OK, e.g. does not hit the
  * transaction size limit (which should only consider the hashes).
  */
+@Ignore("ENT-5679: This test triggers OOM errors")
 class LargeTransactionsTest {
     private companion object {
         val BOB = TestIdentity(BOB_NAME, 80).party

node/src/integration-test/kotlin/net/corda/node/services/vault/VaultObserverExceptionTest.kt

@@ -51,6 +51,7 @@ import kotlin.test.assertTrue
 class VaultObserverExceptionTest {
     companion object {
 
+        val waitForFlowDuration = 45.seconds
         val log = contextLogger()
 
         private fun testCordapps() = listOf(
@@ -98,7 +99,7 @@ class VaultObserverExceptionTest {
                 "Syntax Error in Custom SQL",
                 CreateStateFlow.errorTargetsToNum(CreateStateFlow.ErrorTarget.ServiceSqlSyntaxError)
             ).returnValue.then { testControlFuture.complete(false) }
-            val foundExpectedException = testControlFuture.getOrThrow(30.seconds)
+            val foundExpectedException = testControlFuture.getOrThrow(waitForFlowDuration)
 
             Assert.assertTrue(foundExpectedException)
         }
@@ -132,7 +133,7 @@ class VaultObserverExceptionTest {
                 "Syntax Error in Custom SQL",
                 CreateStateFlow.errorTargetsToNum(CreateStateFlow.ErrorTarget.ServiceSqlSyntaxError)
             ).returnValue.then { testControlFuture.complete(false) }
-            val foundExpectedException = testControlFuture.getOrThrow(30.seconds)
+            val foundExpectedException = testControlFuture.getOrThrow(waitForFlowDuration)
 
             Assert.assertTrue(foundExpectedException)
         }
@@ -223,7 +224,7 @@ class VaultObserverExceptionTest {
             assertFailsWith<TimeoutException>("PersistenceException") {
                 aliceNode.rpc.startFlow(CreateStateFlow::Initiator, "EntityManager", errorTargetsToNum(
                         CreateStateFlow.ErrorTarget.TxInvalidState))
-                        .returnValue.getOrThrow(30.seconds)
+                        .returnValue.getOrThrow(waitForFlowDuration)
             }
         }
         Assert.assertTrue("Flow has not been to hospital", counter > 0)
@@ -259,7 +260,7 @@ class VaultObserverExceptionTest {
                             CreateStateFlow.ErrorTarget.TxInvalidState,
                             CreateStateFlow.ErrorTarget.FlowSwallowErrors))
             val flowResult = flowHandle.returnValue
-            assertFailsWith<TimeoutException>("PersistenceException") { flowResult.getOrThrow(30.seconds) }
+            assertFailsWith<TimeoutException>("PersistenceException") { flowResult.getOrThrow(waitForFlowDuration) }
             Assert.assertTrue("Flow has not been to hospital", counter > 0)
         }
     }
@@ -290,7 +291,7 @@ class VaultObserverExceptionTest {
                 log.info("Flow has finished")
                 testControlFuture.set(false)
             }
-            Assert.assertTrue("Flow has not been kept in hospital", testControlFuture.getOrThrow(30.seconds))
+            Assert.assertTrue("Flow has not been kept in hospital", testControlFuture.getOrThrow(waitForFlowDuration))
         }
     }
 
@@ -309,7 +310,7 @@ class VaultObserverExceptionTest {
                     CreateStateFlow.ErrorTarget.ServiceSqlSyntaxError,
                     CreateStateFlow.ErrorTarget.ServiceSwallowErrors))
             val flowResult = flowHandle.returnValue
-            flowResult.getOrThrow(30.seconds)
+            flowResult.getOrThrow(waitForFlowDuration)
         }
     }
 
@@ -410,7 +411,7 @@ class VaultObserverExceptionTest {
                     testControlFuture.complete(true)
                 }
                 startNode(providedName = ALICE_NAME, rpcUsers = listOf(aliceUser), startInSameProcess = true).getOrThrow()
-                assert(testControlFuture.getOrThrow(30.seconds))
+                assert(testControlFuture.getOrThrow(waitForFlowDuration))
             } else {
                 throw IllegalStateException("Out of process node is still up and running!")
             }
@@ -460,7 +461,7 @@ class VaultObserverExceptionTest {
                     CreateStateFlow::Initiator,
                     "AllGood",
                     errorTargetsToNum(CreateStateFlow.ErrorTarget.ServiceSqlSyntaxErrorOnConsumed)
-                ).returnValue.getOrThrow(30.seconds)
+                ).returnValue.getOrThrow(waitForFlowDuration)
 
                 println("Created new state")
 
@@ -551,7 +552,7 @@ class VaultObserverExceptionTest {
                     "AllGood",
                     // should be a hospital exception
                     errorTargetsToNum(CreateStateFlow.ErrorTarget.ServiceSqlSyntaxErrorOnConsumed)
-                ).returnValue.getOrThrow(30.seconds)
+                ).returnValue.getOrThrow(waitForFlowDuration)
 
                 val flowHandle = aliceNode.rpc.startFlow(
                     SendStateFlow::PassErroneousOwnableState,
@@ -632,7 +633,7 @@ class VaultObserverExceptionTest {
                     CreateStateFlow::Initiator,
                     "AllGood",
                     errorTargetsToNum(CreateStateFlow.ErrorTarget.NoError)
-                ).returnValue.getOrThrow(30.seconds)
+                ).returnValue.getOrThrow(waitForFlowDuration)
 
                 aliceNode.rpc.startFlow(
                     SendStateFlow::PassErroneousOwnableState,
@@ -709,7 +710,7 @@ class VaultObserverExceptionTest {
                     CreateStateFlow::Initiator,
                     "AllGood",
                     errorTargetsToNum(CreateStateFlow.ErrorTarget.ServiceSqlSyntaxErrorOnConsumed)
-                ).returnValue.getOrThrow(30.seconds)
+                ).returnValue.getOrThrow(waitForFlowDuration)
 
                 val flowHandle = aliceNode.rpc.startFlow(
                     SendStateFlow::PassErroneousOwnableState,
@@ -764,7 +765,7 @@ class VaultObserverExceptionTest {
                 "Flow ${SubscribingRawUpdatesFlow::class.java.name} tried to access VaultService.rawUpdates " +
                         "- Rx.Observables should only be accessed outside the context of a flow "
             ) {
-                flowHandle.returnValue.getOrThrow(30.seconds)
+                flowHandle.returnValue.getOrThrow(waitForFlowDuration)
             }
         }
     }

node/src/main/kotlin/net/corda/node/services/network/NetworkMapUpdater.kt

@@ -153,6 +153,11 @@ class NetworkMapUpdater(private val networkMapCache: NetworkMapCacheInternal,
                 val nextScheduleDelay = try {
                     updateNetworkMapCache()
                 } catch (e: Exception) {
+                    // Check to see if networkmap was reachable before and cached information exists
+                    if (networkMapCache.allNodeHashes.size > 1) {
+                        logger.debug("Networkmap Service unreachable but more than one nodeInfo entries found in the cache. Allowing node start-up to proceed.")
+                        networkMapCache.nodeReady.set(null)
+                    }
                     logger.warn("Error encountered while updating network map, will retry in $defaultRetryInterval", e)
                     defaultRetryInterval
                 }

testing/node-driver/src/main/kotlin/net/corda/testing/driver/Driver.kt

@@ -26,6 +26,7 @@ import net.corda.testing.node.internal.genericDriver
 import net.corda.testing.node.internal.getTimestampAsDirectoryName
 import net.corda.testing.node.internal.newContext
 import rx.Observable
+import java.io.File
 import java.nio.file.Path
 import java.nio.file.Paths
 import java.util.concurrent.atomic.AtomicInteger
@@ -66,6 +67,8 @@ interface NodeHandle : AutoCloseable {
     fun stop()
 }
 
+fun NodeHandle.logFile(): File = (baseDirectory / "logs").toFile().walk().filter { it.name.startsWith("node-") && it.extension == "log" }.single()
+
 /** Interface which represents an out of process node and exposes its process handle. **/
 @DoNotImplement
 interface OutOfProcess : NodeHandle {

testing/test-common/src/main/resources/log4j2-test.xml

@@ -1,5 +1,5 @@
 <?xml version="1.0" encoding="UTF-8"?>
-<Configuration status="info" packages="net.corda.common.logging">
+<Configuration status="info">
 
     <Properties>
         <Property name="log-path">${sys:log-path:-logs}</Property>
@@ -63,17 +63,14 @@
 
         <Rewrite name="Console-ErrorCode-Appender">
             <AppenderRef ref="Console-Appender"/>
-            <ErrorCodeRewritePolicy/>
         </Rewrite>
 
         <Rewrite name="Console-ErrorCode-Appender-Println">
             <AppenderRef ref="Console-Appender-Println"/>
-            <ErrorCodeRewritePolicy/>
         </Rewrite>
 
         <Rewrite name="RollingFile-ErrorCode-Appender">
             <AppenderRef ref="RollingFile-Appender"/>
-            <ErrorCodeRewritePolicy/>
         </Rewrite>
     </Appenders>
 

testing/test-db/src/test/resources/log4j2-test.xml

@@ -1,5 +1,5 @@
 <?xml version="1.0" encoding="UTF-8"?>
-<Configuration status="info" packages="net.corda.common.logging">
+<Configuration status="info">
 
     <Properties>
         <Property name="log-path">${sys:log-path:-logs}</Property>
@@ -65,17 +65,14 @@
 
         <Rewrite name="Console-ErrorCode-Appender">
             <AppenderRef ref="Console-Appender"/>
-            <ErrorCodeRewritePolicy/>
         </Rewrite>
 
         <Rewrite name="Console-ErrorCode-Appender-Println">
             <AppenderRef ref="Console-Appender-Println"/>
-            <ErrorCodeRewritePolicy/>
         </Rewrite>
 
         <Rewrite name="RollingFile-ErrorCode-Appender">
             <AppenderRef ref="RollingFile-Appender"/>
-            <ErrorCodeRewritePolicy/>
         </Rewrite>
     </Appenders>