Made logging easier

This commit is contained in:
nathan 2020-09-09 12:30:07 +02:00
parent ce5eb8cb77
commit d0787fc12f
5 changed files with 300 additions and 66 deletions

View File

@ -128,6 +128,12 @@ abstract class BaseTest {
init {
println("---- " + this.javaClass.simpleName)
// setLogLevel(Level.INFO)
setLogLevel(Level.TRACE)
// setLogLevel(Level.DEBUG)
}
fun setLogLevel(level: Level) {
// assume SLF4J is bound to logback in the current environment
val rootLogger = LoggerFactory.getLogger(org.slf4j.Logger.ROOT_LOGGER_NAME) as Logger
val context = rootLogger.loggerContext
@ -135,13 +141,7 @@ abstract class BaseTest {
jc.context = context
context.reset() // override default configuration
// rootLogger.setLevel(Level.OFF)
// rootLogger.level = Level.INFO
rootLogger.level = Level.TRACE
// rootLogger.level = Level.DEBUG
// rootLogger.level = Level.ALL
rootLogger.level = level
// we only want error messages
val kryoLogger = LoggerFactory.getLogger("com.esotericsoftware") as Logger

View File

@ -78,7 +78,7 @@ class RmiDelayedInvocationTest : BaseTest() {
val totalRuns = 100
var abort = false
System.err.println("Running for $totalRuns iterations....")
connection.logger.error("Running for $totalRuns iterations....")
for (i in 0 until totalRuns) {
if (abort) {
@ -94,13 +94,13 @@ class RmiDelayedInvocationTest : BaseTest() {
try {
(iterateLock as Object).wait(1)
} catch (e: InterruptedException) {
System.err.println("Failed after: $i")
connection.logger.error("Failed after: $i")
e.printStackTrace()
abort = true
}
}
}
System.err.println("Done with delay invocation test")
connection.logger.error("Done with delay invocation test")
stopEndPoints()
}

View File

@ -16,8 +16,6 @@
package dorkboxTest.network.rmi
import ch.qos.logback.classic.Level
import ch.qos.logback.classic.Logger
import ch.qos.logback.classic.joran.JoranConfigurator
import dorkbox.network.Client
import dorkbox.network.Configuration
import dorkbox.network.Server
@ -27,74 +25,30 @@ import dorkboxTest.network.BaseTest
import kotlinx.coroutines.runBlocking
import org.junit.Assert
import org.junit.Test
import org.slf4j.LoggerFactory
import java.util.concurrent.atomic.AtomicLong
class RmiDelayedInvocationSpamTest : BaseTest() {
class RmiSpamAsyncTest : BaseTest() {
private val counter = AtomicLong(0)
private val RMI_ID = 12251
var async = true
private fun setupLogBefore() {
// assume SLF4J is bound to logback in the current environment
val rootLogger = LoggerFactory.getLogger(org.slf4j.Logger.ROOT_LOGGER_NAME) as Logger
val context = rootLogger.loggerContext
val jc = JoranConfigurator()
jc.context = context
context.reset() // override default configuration
init {
// the logger cannot keep-up if it's on trace
rootLogger.level = Level.DEBUG
}
private fun setupLogAfter() {
// assume SLF4J is bound to logback in the current environment
val rootLogger = LoggerFactory.getLogger(org.slf4j.Logger.ROOT_LOGGER_NAME) as Logger
val context = rootLogger.loggerContext
val jc = JoranConfigurator()
jc.context = context
context.reset() // override default configuration
// the logger cannot keep-up if it's on trace
rootLogger.level = Level.TRACE
setLogLevel(Level.DEBUG)
}
@Test
fun rmiNetwork() {
fun rmiNetworkAsync() {
runBlocking {
async = false
rmi { configuration ->
configuration.enableIpcForLoopback = false
}
}
}
@Test
fun rmiNetworkAync() {
setupLogBefore()
runBlocking {
async = true
rmi { configuration ->
configuration.enableIpcForLoopback = false
}
}
}
@Test
fun rmiIpc() {
runBlocking {
async = false
rmi()
}
}
@Test
fun rmiIpcAsync() {
setupLogBefore()
runBlocking {
async = true
rmi()
}
}
@ -106,8 +60,8 @@ class RmiDelayedInvocationSpamTest : BaseTest() {
suspend fun rmi(config: (Configuration) -> Unit = {}) {
val server: Server<Connection>
val mod = if (async) 10_000L else 200L
val totalRuns = if (async) 1_000_000 else 1_000
val mod = 100_000L
val totalRuns = 1_000_000
run {
val configuration = serverConfig()
@ -123,23 +77,24 @@ class RmiDelayedInvocationSpamTest : BaseTest() {
}
val client: Client<Connection>
run {
val configuration = clientConfig()
config(configuration)
val client = Client<Connection>(configuration)
client = Client<Connection>(configuration)
addEndPoint(client)
client.onConnect { connection ->
val remoteObject = connection.getGlobalObject<TestObject>(RMI_ID)
val obj = remoteObject as RemoteObject
obj.async = async
obj.async = true
var started = false
for (i in 0 until totalRuns) {
if (!started) {
started = true
System.err.println("Running for $totalRuns iterations....")
connection.logger.error("Running for $totalRuns iterations....")
}
if (i % mod == 0L) {
@ -150,7 +105,7 @@ class RmiDelayedInvocationSpamTest : BaseTest() {
try {
remoteObject.setOther(i.toLong())
} catch (e: Exception) {
System.err.println("Timeout when calling RMI method")
connection.logger.error("Timeout when calling RMI method")
e.printStackTrace()
}
}
@ -165,6 +120,8 @@ class RmiDelayedInvocationSpamTest : BaseTest() {
waitForThreads(200)
Assert.assertEquals(totalRuns.toLong(), counter.get())
client.logger.error("kryos generated: ${client.config.serialization.getInitializedKryoCount()}")
server.logger.error("kryos generated: ${server.config.serialization.getInitializedKryoCount()}")
}
private interface TestObject {

View File

@ -0,0 +1,138 @@
/*
* Copyright 2020 dorkbox, llc
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package dorkboxTest.network.rmi
import dorkbox.network.Client
import dorkbox.network.Configuration
import dorkbox.network.Server
import dorkbox.network.connection.Connection
import dorkbox.network.rmi.RemoteObject
import dorkboxTest.network.BaseTest
import kotlinx.coroutines.runBlocking
import org.junit.Assert
import org.junit.Test
import java.util.concurrent.atomic.AtomicLong
class RmiSpamSyncSuspendingTest : BaseTest() {
private val counter = AtomicLong(0)
private val RMI_ID = 12251
init {
// the logger cannot keep-up if it's on trace
setLogLevel(ch.qos.logback.classic.Level.DEBUG)
}
@Test
fun rmiNetwork() {
runBlocking {
rmi { configuration ->
configuration.enableIpcForLoopback = false
}
}
}
@Test
fun rmiIpc() {
runBlocking {
rmi()
}
}
/**
* In this test the server has two objects in an object space. The client
* uses the first remote object to get the second remote object.
*/
suspend fun rmi(config: (Configuration) -> Unit = {}) {
val server: Server<Connection>
val mod = 400L
val totalRuns = 4_000
run {
val configuration = serverConfig()
config(configuration)
configuration.serialization.registerRmi(TestObject::class.java, TestObjectImpl::class.java)
server = Server(configuration)
addEndPoint(server)
server.saveGlobalObject(TestObjectImpl(counter), RMI_ID)
server.bind()
}
val client: Client<Connection>
run {
val configuration = clientConfig()
config(configuration)
client = Client(configuration)
addEndPoint(client)
client.onConnect { connection ->
val remoteObject = connection.getGlobalObject<TestObject>(RMI_ID)
val obj = remoteObject as RemoteObject
obj.async = false
var started = false
for (i in 0 until totalRuns) {
if (!started) {
started = true
connection.logger.error("Running for $totalRuns iterations....")
}
if (i % mod == 0L) {
// this doesn't always output to the console. weird.
client.logger.error("$i")
}
try {
remoteObject.setOther(i.toLong())
} catch (e: Exception) {
connection.logger.error("Timeout when calling RMI method")
e.printStackTrace()
}
}
// have to do this first, so it will wait for the client responses!
// if we close the client first, the connection will be closed, and the responses will never arrive to the server
stopEndPoints()
}
client.connect()
}
waitForThreads()
Assert.assertEquals(totalRuns.toLong(), counter.get())
client.logger.error("kryos generated: ${client.config.serialization.getInitializedKryoCount()}")
server.logger.error("kryos generated: ${server.config.serialization.getInitializedKryoCount()}")
}
private interface TestObject {
suspend fun setOther(value: Long): Boolean
}
private class TestObjectImpl(private val counter: AtomicLong) : TestObject {
@Override
override suspend fun setOther(aFloat: Long): Boolean {
counter.getAndIncrement()
return true
}
}
}

View File

@ -0,0 +1,139 @@
/*
* Copyright 2020 dorkbox, llc
*
* Licensed under the Apache License, Version 2.0 (the "License");
* you may not use this file except in compliance with the License.
* You may obtain a copy of the License at
*
* http://www.apache.org/licenses/LICENSE-2.0
*
* Unless required by applicable law or agreed to in writing, software
* distributed under the License is distributed on an "AS IS" BASIS,
* WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
* See the License for the specific language governing permissions and
* limitations under the License.
*/
package dorkboxTest.network.rmi
import ch.qos.logback.classic.Level
import dorkbox.network.Client
import dorkbox.network.Configuration
import dorkbox.network.Server
import dorkbox.network.connection.Connection
import dorkbox.network.rmi.RemoteObject
import dorkboxTest.network.BaseTest
import kotlinx.coroutines.runBlocking
import org.junit.Assert
import org.junit.Test
import java.util.concurrent.atomic.AtomicLong
class RmiSpamSyncTest : BaseTest() {
private val counter = AtomicLong(0)
private val RMI_ID = 12251
init {
// the logger cannot keep-up if it's on trace
setLogLevel(Level.DEBUG)
}
@Test
fun rmiNetwork() {
runBlocking {
rmi { configuration ->
configuration.enableIpcForLoopback = false
}
}
}
@Test
fun rmiIpc() {
runBlocking {
rmi()
}
}
/**
* In this test the server has two objects in an object space. The client
* uses the first remote object to get the second remote object.
*/
suspend fun rmi(config: (Configuration) -> Unit = {}) {
val server: Server<Connection>
val mod = 400L
val totalRuns = 1_000
run {
val configuration = serverConfig()
config(configuration)
configuration.serialization.registerRmi(TestObject::class.java, TestObjectImpl::class.java)
server = Server(configuration)
addEndPoint(server)
server.saveGlobalObject(TestObjectImpl(counter), RMI_ID)
server.bind()
}
val client: Client<Connection>
run {
val configuration = clientConfig()
config(configuration)
client = Client(configuration)
addEndPoint(client)
client.onConnect { connection ->
val remoteObject = connection.getGlobalObject<TestObject>(RMI_ID)
val obj = remoteObject as RemoteObject
obj.async = false
var started = false
for (i in 0 until totalRuns) {
if (!started) {
started = true
connection.logger.error("Running for $totalRuns iterations....")
}
if (i % mod == 0L) {
// this doesn't always output to the console. weird.
client.logger.error("$i")
}
try {
remoteObject.setOther(i.toLong())
} catch (e: Exception) {
connection.logger.error("Timeout when calling RMI method")
e.printStackTrace()
}
}
// have to do this first, so it will wait for the client responses!
// if we close the client first, the connection will be closed, and the responses will never arrive to the server
stopEndPoints()
}
client.connect()
}
waitForThreads()
Assert.assertEquals(totalRuns.toLong(), counter.get())
client.logger.error("kryos generated: ${client.config.serialization.getInitializedKryoCount()}")
server.logger.error("kryos generated: ${server.config.serialization.getInitializedKryoCount()}")
}
private interface TestObject {
fun setOther(value: Long): Boolean
}
private class TestObjectImpl(private val counter: AtomicLong) : TestObject {
@Override
override fun setOther(aFloat: Long): Boolean {
counter.getAndIncrement()
return true
}
}
}