diff --git a/build.gradle b/build.gradle index 185056b20a..44a1bbcbe6 100644 --- a/build.gradle +++ b/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") diff --git a/common/logging/src/main/kotlin/net/corda/common/logging/ErrorCodeRewritePolicy.kt b/common/logging/src/main/kotlin/net/corda/common/logging/ErrorCodeRewritePolicy.kt deleted file mode 100644 index 5f0e24bef9..0000000000 --- a/common/logging/src/main/kotlin/net/corda/common/logging/ErrorCodeRewritePolicy.kt +++ /dev/null @@ -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() - } - } -} \ No newline at end of file diff --git a/config/dev/log4j2.xml b/config/dev/log4j2.xml index 051518c4a6..02aa604cf4 100644 --- a/config/dev/log4j2.xml +++ b/config/dev/log4j2.xml @@ -1,5 +1,5 @@ - + ${sys:log-path:-logs} @@ -172,21 +172,17 @@ - - - - diff --git a/constants.properties b/constants.properties index 69181a5fa3..fdc1a61211 100644 --- a/constants.properties +++ b/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 diff --git a/node/src/integration-test/kotlin/net/corda/node/AuthDBTests.kt b/node/src/integration-test/kotlin/net/corda/node/AuthDBTests.kt index 70293b6074..7314df162c 100644 --- a/node/src/integration-test/kotlin/net/corda/node/AuthDBTests.kt +++ b/node/src/integration-test/kotlin/net/corda/node/AuthDBTests.kt @@ -22,6 +22,7 @@ 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 @@ -33,7 +34,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 +94,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 +217,7 @@ class AuthDBTests : NodeBasedTest() { @After fun tearDown() { + node?.node?.stop() db.close() } @@ -228,7 +231,7 @@ private data class RoleAndPermissions(val role: String, val permissions: List = emptyList(), roleAndPermissions: List = 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 +272,34 @@ private class UsersDB(name: String, users: List = 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() } } diff --git a/node/src/integration-test/kotlin/net/corda/node/NodeConfigParsingTests.kt b/node/src/integration-test/kotlin/net/corda/node/NodeConfigParsingTests.kt index fd2f7d7507..5f243fe780 100644 --- a/node/src/integration-test/kotlin/net/corda/node/NodeConfigParsingTests.kt +++ b/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`() { diff --git a/node/src/integration-test/kotlin/net/corda/node/logging/ErrorCodeLoggingTests.kt b/node/src/integration-test/kotlin/net/corda/node/logging/ErrorCodeLoggingTests.kt deleted file mode 100644 index e1db95e528..0000000000 --- a/node/src/integration-test/kotlin/net/corda/node/logging/ErrorCodeLoggingTests.kt +++ /dev/null @@ -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() { - 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() \ No newline at end of file diff --git a/node/src/integration-test/kotlin/net/corda/node/services/statemachine/LargeTransactionsTest.kt b/node/src/integration-test/kotlin/net/corda/node/services/statemachine/LargeTransactionsTest.kt index 6d23503efb..7830412980 100644 --- a/node/src/integration-test/kotlin/net/corda/node/services/statemachine/LargeTransactionsTest.kt +++ b/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 diff --git a/node/src/integration-test/kotlin/net/corda/node/services/vault/VaultObserverExceptionTest.kt b/node/src/integration-test/kotlin/net/corda/node/services/vault/VaultObserverExceptionTest.kt index 86bb3b2931..134071403d 100644 --- a/node/src/integration-test/kotlin/net/corda/node/services/vault/VaultObserverExceptionTest.kt +++ b/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("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("PersistenceException") { flowResult.getOrThrow(30.seconds) } + assertFailsWith("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) } } } diff --git a/node/src/main/kotlin/net/corda/node/services/network/NetworkMapUpdater.kt b/node/src/main/kotlin/net/corda/node/services/network/NetworkMapUpdater.kt index 7ff18232a2..aba03a5074 100644 --- a/node/src/main/kotlin/net/corda/node/services/network/NetworkMapUpdater.kt +++ b/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 } diff --git a/testing/node-driver/src/main/kotlin/net/corda/testing/driver/Driver.kt b/testing/node-driver/src/main/kotlin/net/corda/testing/driver/Driver.kt index 8c16c40a34..6481a29714 100644 --- a/testing/node-driver/src/main/kotlin/net/corda/testing/driver/Driver.kt +++ b/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 { diff --git a/testing/test-common/src/main/resources/log4j2-test.xml b/testing/test-common/src/main/resources/log4j2-test.xml index d8d489af1f..45910c8ca5 100644 --- a/testing/test-common/src/main/resources/log4j2-test.xml +++ b/testing/test-common/src/main/resources/log4j2-test.xml @@ -1,5 +1,5 @@ - + ${sys:log-path:-logs} @@ -63,17 +63,14 @@ - - - diff --git a/testing/test-db/src/test/resources/log4j2-test.xml b/testing/test-db/src/test/resources/log4j2-test.xml index d0941363a9..35b51709ed 100644 --- a/testing/test-db/src/test/resources/log4j2-test.xml +++ b/testing/test-db/src/test/resources/log4j2-test.xml @@ -1,5 +1,5 @@ - + ${sys:log-path:-logs} @@ -65,17 +65,14 @@ - - -