Skip to content

Commit

Permalink
add logging level for requestmatchers
Browse files Browse the repository at this point in the history
  • Loading branch information
froks committed Feb 10, 2022
1 parent 5c924b3 commit 7d8d4d1
Show file tree
Hide file tree
Showing 5 changed files with 56 additions and 21 deletions.
34 changes: 27 additions & 7 deletions src/main/kotlin/SimDsl.kt
Original file line number Diff line number Diff line change
Expand Up @@ -196,6 +196,7 @@ class RequestMatcher(
val name: String?,
val requestBytes: ByteArray?,
val requestRegex: Regex?,
val loglevel: LogLevel = LogLevel.DEBUG,
val responseHandler: RequestResponseHandler
) : DataStorage() {
init {
Expand Down Expand Up @@ -242,6 +243,13 @@ fun MutableList<RequestMatcher>.removeByName(name: String): RequestMatcher? {

data class ResetHandler(val name: String?, val handler: (SimEcu) -> Unit)

enum class LogLevel {
ERROR,
INFO,
DEBUG,
TRACE,
}

open class RequestsData(
val name: String,
/**
Expand Down Expand Up @@ -284,8 +292,14 @@ open class RequestsData(
* Define request-matcher & response-handler for a gateway or ecu by using an
* exact matching byte-array
*/
fun request(request: ByteArray, name: String? = null, response: RequestResponseHandler = {}): RequestMatcher {
val req = RequestMatcher(name = name, requestBytes = request, requestRegex = null, responseHandler = response)
fun request(request: ByteArray, name: String? = null, loglevel: LogLevel = LogLevel.DEBUG, response: RequestResponseHandler = {}): RequestMatcher {
val req = RequestMatcher(
name = name,
requestBytes = request,
requestRegex = null,
loglevel = loglevel,
responseHandler = response
)
requests.add(req)
return req
}
Expand All @@ -300,8 +314,14 @@ open class RequestsData(
* Note: Take the maximal string length [requestRegexMatchBytes] into
* account
*/
fun request(reqRegex: Regex, name: String? = null, response: RequestResponseHandler = {}): RequestMatcher {
val req = RequestMatcher(name = name, requestBytes = null, requestRegex = reqRegex, responseHandler = response)
fun request(reqRegex: Regex, name: String? = null, loglevel: LogLevel = LogLevel.DEBUG, response: RequestResponseHandler = {}): RequestMatcher {
val req = RequestMatcher(
name = name,
requestBytes = null,
requestRegex = reqRegex,
loglevel = loglevel,
responseHandler = response
)
requests.add(req)
return req
}
Expand All @@ -317,11 +337,11 @@ open class RequestsData(
* is automatically converted into a regular expression by replacing all "[]" with ".*",
* turning it into uppercase, and removing all spaces.
*/
fun request(reqHex: String, name: String? = null, response: RequestResponseHandler = {}) {
fun request(reqHex: String, name: String? = null, loglevel: LogLevel = LogLevel.DEBUG, response: RequestResponseHandler = {}) {
if (isRegex(reqHex)) {
request(regexifyRequestHex(reqHex), name, response)
request(regexifyRequestHex(reqHex), name, loglevel, response)
} else {
request(reqHex.decodeHex(), name, response)
request(reqHex.decodeHex(), name, loglevel, response)
}
}

Expand Down
30 changes: 19 additions & 11 deletions src/main/kotlin/SimEcu.kt
Original file line number Diff line number Diff line change
Expand Up @@ -80,7 +80,7 @@ class SimEcu(private val data: EcuData) : SimulatedEcu(data.toEcuConfig()) {
return false
}

override fun handleRequestIfBusy(request: UdsMessage){
override fun handleRequestIfBusy(request: UdsMessage) {
if (handleInterceptors(request, true)) {
logger.debugIf { "[${name}] Incoming busy request ${request.message.toHexString(limit = 10)} was handled by interceptors" }
}
Expand Down Expand Up @@ -110,11 +110,11 @@ class SimEcu(private val data: EcuData) : SimulatedEcu(data.toEcuConfig()) {
requestIter.requestRegex!!.matches(normalizedRequest)
}
} catch (e: Exception) {
logger.error("[${name}] Error while matching requests: ${e.message}")
logger.error("Error while matching requests for $name: ${e.message}", e)
throw e
}

logger.traceIf { "[${name}] Request: '${request.message.toHexString(limit = 10)}' try match '$requestIter' -> $matches" }
logger.traceIf { "Request for $name: '${request.message.toHexString(limit = 10)}' try match '$requestIter' -> $matches" }

if (!matches) {
continue
Expand All @@ -123,22 +123,22 @@ class SimEcu(private val data: EcuData) : SimulatedEcu(data.toEcuConfig()) {
val responseData = ResponseData(caller = requestIter, request = request, ecu = this)
requestIter.responseHandler.invoke(responseData)
if (responseData.continueMatching) {
logger.debugIf { "[${name}] Request: '${request.message.toHexString(limit = 10)}' matched '$requestIter' -> Continue matching" }
logger.logForRequest(requestIter) { "Request for $name: '${request.message.toHexString(limit = 10)}' matched '$requestIter' -> Continue matching" }
continue
} else if (responseData.response.isNotEmpty()) {
logger.debugIf { "[${name}] Request: '${request.message.toHexString(limit = 10)}' matched '$requestIter' -> Send response '${responseData.response.toHexString(limit = 10)}'" }
logger.logForRequest(requestIter) { "Request for $name: '${request.message.toHexString(limit = 10)}' matched '$requestIter' -> Send response '${responseData.response.toHexString(limit = 10)}'" }
sendResponse(request, responseData.response)
} else {
logger.debugIf { "[${name}] Request: '${request.message.toHexString(limit = 10)}' matched '$requestIter' -> No response" }
logger.logForRequest(requestIter) { "Request for $name: '${request.message.toHexString(limit = 10)}' matched '$requestIter' -> No response" }
}
return
}

if (this.data.nrcOnNoMatch) {
logger.debugIf { "[${name}] Request: '${request.message.toHexString(limit = 10)}' no matching request found -> Sending NRC" }
logger.debugIf { "Request for $name: '${request.message.toHexString(limit = 10)}' no matching request found -> Sending NRC" }
sendResponse(request, byteArrayOf(0x7F, request.message[0], NrcError.RequestOutOfRange))
} else {
logger.debugIf { "[${name}] Request: '${request.message.toHexString(limit = 10)}' no matching request found -> Ignore (nrcOnNoMatch = false)" }
logger.debugIf { "Request for $name: '${request.message.toHexString(limit = 10)}' no matching request found -> Ignore (nrcOnNoMatch = false)" }
}
}

Expand All @@ -153,7 +153,7 @@ class SimEcu(private val data: EcuData) : SimulatedEcu(data.toEcuConfig()) {
alsoCallWhenEcuIsBusy: Boolean = false,
interceptor: InterceptorResponseHandler
): String {
logger.traceIf { "[${this.name}] Adding interceptor '$name' for $duration (busy: $alsoCallWhenEcuIsBusy)"}
logger.traceIf { "Adding interceptor '$name' for $duration (busy: $alsoCallWhenEcuIsBusy) in ecu $name"}

// expires at expirationTime
val expirationTime = if (duration == Duration.INFINITE) Long.MAX_VALUE else System.nanoTime() + duration.inWholeNanoseconds
Expand All @@ -180,7 +180,7 @@ class SimEcu(private val data: EcuData) : SimulatedEcu(data.toEcuConfig()) {
* Please note that the internal resolution for delay is milliseconds
*/
fun addOrReplaceTimer(name: String, delay: Duration, handler: TimerTask.() -> Unit) {
logger.traceIf { "[${this.name}] Adding or replacing timer '$name' to be executed after $delay"}
logger.traceIf { "Adding or replacing timer '$name' for $name to be executed after $delay"}

synchronized(mainTimer) {
timers[name]?.cancel()
Expand All @@ -201,7 +201,7 @@ class SimEcu(private val data: EcuData) : SimulatedEcu(data.toEcuConfig()) {
* Explicitly cancel a running timer
*/
fun cancelTimer(name: String) {
logger.traceIf { "[${this.name}] Cancelling timer '$name'" }
logger.traceIf { "Cancelling timer '$name' for $name" }
synchronized(mainTimer) {
timers[name]?.cancel()
timers.remove(name)
Expand Down Expand Up @@ -241,3 +241,11 @@ class SimEcu(private val data: EcuData) : SimulatedEcu(data.toEcuConfig()) {
}
}
}

fun Logger.logForRequest(request: RequestMatcher, t: Throwable? = null, supplier: () -> String) =
when (request.loglevel) {
LogLevel.ERROR -> this.errorIf(t, supplier)
LogLevel.INFO -> this.infoIf(t, supplier)
LogLevel.DEBUG -> this.debugIf(t, supplier)
LogLevel.TRACE -> this.traceIf(t, supplier)
}
7 changes: 7 additions & 0 deletions src/main/kotlin/library/LoggerExtensions.kt
Original file line number Diff line number Diff line change
Expand Up @@ -19,3 +19,10 @@ fun Logger.infoIf(t: Throwable? = null, supplier: () -> String) {
this.info(supplier.invoke(), t)
}
}

fun Logger.errorIf(t: Throwable? = null, supplier: () -> String) {
if (this.isErrorEnabled) {
this.error(supplier.invoke(), t)
}
}

4 changes: 2 additions & 2 deletions src/main/kotlin/library/SimulatedEcu.kt
Original file line number Diff line number Diff line change
Expand Up @@ -13,12 +13,12 @@ open class SimulatedEcu(val config: EcuConfig) {
private val isBusy: AtomicBoolean = AtomicBoolean(false)

open fun handleRequest(request: UdsMessage) {
logger.debugIf { "[${name}] Handle Request message: ${request.message.toHexString(limit = 20)}" }
logger.debugIf { "Handle Request message: ${request.message.toHexString(limit = 20)} for $name" }
}

open fun handleRequestIfBusy(request: UdsMessage) {
// Busy NRC
logger.debugIf { "[${name}] ECU is busy, sending busy-NRC" }
logger.debugIf { "ECU $name is busy, sending busy-NRC" }
request.respond(byteArrayOf(0x7f, request.message[0], 0x21))
}

Expand Down
2 changes: 1 addition & 1 deletion src/main/resources/logback.xml
Original file line number Diff line number Diff line change
Expand Up @@ -3,7 +3,7 @@
<!-- encoders are assigned the type
ch.qos.logback.classic.encoder.PatternLayoutEncoder by default -->
<encoder>
<pattern>%cyan(%d{HH:mm:ss.SSS}) %highlight(%-5level) %green([%thread]) %magenta(%logger{12}) %boldWhite(%mdc{ecu:-NONE}) %msg%n</pattern>
<pattern>%cyan(%d{HH:mm:ss.SSS}) %highlight(%-5level) %green([%thread]) %magenta(%logger{12}) %boldWhite([%mdc{ecu:-NONE}]) %msg%n</pattern>
</encoder>
</appender>

Expand Down

0 comments on commit 7d8d4d1

Please sign in to comment.