commit ad7171c999f48236b459b0b75a8b0b77e7399a48
parent 277c533b1bc490596ef8831f32449d7319843461
Author: Antoine A <>
Date: Tue, 23 Jan 2024 14:31:25 +0100
Configure ebics logging via CLI flags
Diffstat:
8 files changed, 146 insertions(+), 131 deletions(-)
diff --git a/contrib/nexus.conf b/contrib/nexus.conf
@@ -41,11 +41,9 @@ SQL_DIR = $DATADIR/sql/
[nexus-fetch]
FREQUENCY = 30m
-STATEMENT_LOG_DIRECTORY = /tmp/nexus-downloads/
[nexus-submit]
FREQUENCY = 30m
-SUBMISSIONS_LOG_DIRECTORY = /tmp/nexus-uploads/
[nexus-httpd]
PORT = 8080
diff --git a/integration/conf/netzbon.conf b/integration/conf/netzbon.conf
@@ -20,11 +20,9 @@ NAME = Genossenschaft Netz Soziale Oekonomie
[nexus-fetch]
FREQUENCY = 5s
-STATEMENT_LOG_DIRECTORY = test/netzbon/fetch
[nexus-submit]
FREQUENCY = 5s
-SUBMISSIONS_LOG_DIRECTORY = test/netzbon/submit
[nexus-postgres]
CONFIG = postgres:///libeufincheck
diff --git a/integration/conf/postfinance.conf b/integration/conf/postfinance.conf
@@ -19,11 +19,9 @@ IBAN = CH7789144474425692816
[nexus-fetch]
FREQUENCY = 5s
-STATEMENT_LOG_DIRECTORY = test/postfinance/fetch
[nexus-submit]
FREQUENCY = 5s
-SUBMISSIONS_LOG_DIRECTORY = test/postfinance/submit
[nexus-postgres]
CONFIG = postgres:///libeufincheck
diff --git a/integration/src/main/kotlin/Main.kt b/integration/src/main/kotlin/Main.kt
@@ -59,10 +59,12 @@ fun ask(question: String): String? {
}
fun CliktCommandTestResult.assertOk(msg: String? = null) {
+ println("$output")
assertEquals(0, statusCode, msg)
}
fun CliktCommandTestResult.assertErr(msg: String? = null) {
+ println("$output")
assertEquals(1, statusCode, msg)
}
@@ -82,6 +84,7 @@ class Cli : CliktCommand("Run integration tests on banks provider") {
val conf = "conf/$name.conf"
val log = "DEBUG"
val flags = " -c $conf -L $log"
+ val ebicsFlags = "$flags --transient --debug-ebics test/$name"
val cfg = loadConfig(conf)
val clientKeysPath = Path(cfg.requireString("nexus-ebics", "client_private_keys_file"))
@@ -91,7 +94,7 @@ class Cli : CliktCommand("Run integration tests on banks provider") {
var hasBankKeys = bankKeysPath.exists()
if (ask("Reset DB ? y/n>") == "y") nexusCmd.test("dbinit -r $flags").assertOk()
- else nexusCmd.test("dbinit $flags").assertOk()
+ else nexusCmd.test("dbinit $flags").assertOk()
val nexusDb = NexusDb("postgresql:///libeufincheck")
when (kind) {
@@ -122,13 +125,13 @@ class Cli : CliktCommand("Run integration tests on banks provider") {
val payto = "payto://iban/CH2989144971918294289?receiver-name=Test"
step("Test fetch transactions")
- nexusCmd.test("ebics-fetch --transient $flags --pinned-start 2022-01-01").assertOk()
+ nexusCmd.test("ebics-fetch $ebicsFlag --pinned-start 2022-01-01").assertOk()
while (true) {
when (ask("Run 'fetch', 'submit', 'tx', 'txs', 'logs', 'ack' or 'exit'>")) {
"fetch" -> {
step("Fetch new transactions")
- nexusCmd.test("ebics-fetch --transient $flags").assertOk()
+ nexusCmd.test("ebics-fetch $ebicsFlags").assertOk()
}
"tx" -> {
step("Test submit one transaction")
@@ -139,7 +142,7 @@ class Cli : CliktCommand("Run integration tests on banks provider") {
initiationTime = Instant.now(),
requestUid = Base32Crockford.encode(randBytes(16))
))
- nexusCmd.test("ebics-submit --transient $flags").assertOk()
+ nexusCmd.test("ebics-submit $ebicsFlags").assertOk()
}
"txs" -> {
step("Test submit many transaction")
@@ -152,19 +155,19 @@ class Cli : CliktCommand("Run integration tests on banks provider") {
requestUid = Base32Crockford.encode(randBytes(16))
))
}
- nexusCmd.test("ebics-submit --transient $flags").assertOk()
+ nexusCmd.test("ebics-submit $ebicsFlags").assertOk()
}
"submit" -> {
step("Submit pending transactions")
- nexusCmd.test("ebics-submit --transient $flags").assertOk()
+ nexusCmd.test("ebics-submit $ebicsFlags").assertOk()
}
"logs" -> {
step("Fetch logs")
- nexusCmd.test("ebics-fetch --transient $flags --only-logs").assertOk()
+ nexusCmd.test("ebics-fetch $ebicsFlags --only-logs").assertOk()
}
"ack" -> {
step("Fetch ack")
- nexusCmd.test("ebics-fetch --transient $flags --only-ack").assertOk()
+ nexusCmd.test("ebics-fetch $ebicsFlags --only-ack").assertOk()
}
"exit" -> break
}
@@ -180,17 +183,17 @@ class Cli : CliktCommand("Run integration tests on banks provider") {
}
step("Test fetch transactions")
- nexusCmd.test("ebics-fetch --transient $flags --pinned-start 2022-01-01").assertOk()
+ nexusCmd.test("ebics-fetch $ebicsFlags --pinned-start 2022-01-01").assertOk()
while (true) {
when (ask("Run 'fetch', 'submit', 'logs', 'ack' or 'exit'>")) {
"fetch" -> {
step("Fetch new transactions")
- nexusCmd.test("ebics-fetch --transient -c $conf").assertOk()
+ nexusCmd.test("ebics-fetch $ebicsFlags").assertOk()
}
"submit" -> {
step("Submit pending transactions")
- nexusCmd.test("ebics-submit --transient -c $conf").assertOk()
+ nexusCmd.test("ebics-submit $ebicsFlags").assertOk()
}
"tx" -> {
step("Submit new transaction")
@@ -202,15 +205,15 @@ class Cli : CliktCommand("Run integration tests on banks provider") {
initiationTime = Instant.now(),
requestUid = Base32Crockford.encode(randBytes(16))
))
- nexusCmd.test("ebics-submit --transient $flags").assertOk()
+ nexusCmd.test("ebics-submit $ebicsFlags").assertOk()
}
"logs" -> {
step("Fetch logs")
- nexusCmd.test("ebics-fetch --transient $flags --only-logs").assertOk()
+ nexusCmd.test("ebics-fetch $ebicsFlags --only-logs").assertOk()
}
"ack" -> {
step("Fetch ack")
- nexusCmd.test("ebics-fetch --transient $flags --only-ack").assertOk()
+ nexusCmd.test("ebics-fetch $ebicsFlags --only-ack").assertOk()
}
"exit" -> break
}
diff --git a/nexus/src/main/kotlin/tech/libeufin/nexus/EbicsFetch.kt b/nexus/src/main/kotlin/tech/libeufin/nexus/EbicsFetch.kt
@@ -70,7 +70,8 @@ data class FetchContext(
* Start date of the returned documents. Only
* used in --transient mode.
*/
- var pinnedStart: Instant? = null
+ var pinnedStart: Instant?,
+ val fileLogger: FileLogger
)
/**
@@ -129,47 +130,6 @@ private suspend inline fun downloadHelper(
}
/**
- * Extracts the archive entries and logs them to the location
- * optionally specified in the configuration. It does nothing,
- * if the configuration lacks the log directory.
- *
- * @param cfg config handle.
- * @param content ZIP bytes from the server.
- * @param nonZip only true when downloading via HAC (EBICS 2)
- */
-fun maybeLogFile(
- cfg: EbicsSetupConfig,
- content: ByteArray,
- nonZip: Boolean = false
-) {
- // Main dir.
- val maybeLogDir = cfg.config.lookupString(
- "nexus-fetch",
- "STATEMENT_LOG_DIRECTORY"
- ) ?: return
- logger.debug("Logging to $maybeLogDir")
- // Subdir based on current day.
- val now = Instant.now()
- val asUtcDate = LocalDate.ofInstant(now, ZoneId.of("UTC"))
- val subDir = "${asUtcDate.year}-${asUtcDate.monthValue}-${asUtcDate.dayOfMonth}"
- // Creating the combined dir.
- val dirs = Path(maybeLogDir, subDir)
- dirs.createDirectories()
- if (nonZip) {
- val f = Path(dirs.toString(), "${now.toDbMicros()}_HAC_response.pain.002.xml")
- f.writeBytes(content)
- } else {
- // Write each ZIP entry in the combined dir.
- content.unzipForEach { fileName, xmlContent ->
- val f = Path(dirs.toString(), "${now.toDbMicros()}_$fileName")
- // Rare: cannot download the same file twice in the same microsecond.
- f.writeText(xmlContent)
- }
- }
-
-}
-
-/**
* Converts the 2-digits fraction value as given by the bank
* (postfinance dialect), to the Taler 8-digit value (db representation).
*
@@ -453,15 +413,13 @@ private suspend fun fetchDocuments(
val lastExecutionTime: Instant? = ctx.pinnedStart ?: requestFrom
logger.debug("Fetching ${ctx.whichDocument} from timestamp: $lastExecutionTime")
// downloading the content
- val maybeContent = downloadHelper(ctx, lastExecutionTime)
- if (maybeContent.isEmpty()) return
- // logging, if the configuration wants.
- maybeLogFile(
- ctx.cfg,
- maybeContent,
- nonZip = ctx.whichDocument == SupportedDocument.PAIN_002_LOGS
+ val content = downloadHelper(ctx, lastExecutionTime)
+ if (content.isEmpty()) return
+ ctx.fileLogger.logFetch(
+ content,
+ ctx.whichDocument == SupportedDocument.PAIN_002_LOGS
)
- ingestDocuments(db, ctx.cfg.currency, maybeContent, ctx.whichDocument)
+ ingestDocuments(db, ctx.cfg.currency, content, ctx.whichDocument)
}
class EbicsFetch: CliktCommand("Fetches bank records. Defaults to camt.054 notifications") {
@@ -505,6 +463,11 @@ class EbicsFetch: CliktCommand("Fetches bank records. Defaults to camt.054 noti
hidden = true
).flag(default = false)
+ private val ebicsLog by option(
+ "--debug-ebics",
+ help = "Log EBICS content at SAVEDIR",
+ )
+
/**
* This function collects the main steps of fetching banking records.
* In this current version, it does not implement long polling, instead
@@ -513,6 +476,7 @@ class EbicsFetch: CliktCommand("Fetches bank records. Defaults to camt.054 noti
* FIXME: reduce code duplication with the submit subcommand.
*/
override fun run() = cliCmd(logger, common.log) {
+ println("start $ebicsLog")
val cfg: EbicsSetupConfig = extractEbicsConfig(common.config)
val dbCfg = cfg.config.dbConfig()
@@ -538,8 +502,12 @@ class EbicsFetch: CliktCommand("Fetches bank records. Defaults to camt.054 noti
clientKeys,
bankKeys,
whichDoc,
- EbicsVersion.three
+ EbicsVersion.three,
+ null,
+ FileLogger(ebicsLog)
)
+ if (whichDoc == SupportedDocument.PAIN_002_LOGS)
+ ctx.ebicsVersion = EbicsVersion.two
if (transient) {
logger.info("Transient mode: fetching once and returning.")
val pinnedStartVal = pinnedStart
@@ -549,8 +517,6 @@ class EbicsFetch: CliktCommand("Fetches bank records. Defaults to camt.054 noti
LocalDate.parse(pinnedStartVal).atStartOfDay(ZoneId.of("UTC")).toInstant()
} else null
ctx.pinnedStart = pinnedStartArg
- if (whichDoc == SupportedDocument.PAIN_002_LOGS)
- ctx.ebicsVersion = EbicsVersion.two
runBlocking {
fetchDocuments(db, ctx)
}
diff --git a/nexus/src/main/kotlin/tech/libeufin/nexus/EbicsSubmit.kt b/nexus/src/main/kotlin/tech/libeufin/nexus/EbicsSubmit.kt
@@ -72,7 +72,8 @@ data class SubmissionContext(
/**
* Bank EBICS public keys.
*/
- val bankPublicKeysFile: BankPublicKeysFile
+ val bankPublicKeysFile: BankPublicKeysFile,
+ val fileLogger: FileLogger
)
/**
@@ -85,43 +86,6 @@ class NexusSubmitException(
val stage: NexusSubmissionStage
) : Exception(msg, cause)
-
-/**
- * Optionally logs the pain.001 in the log directory, if the
- * configuration had this latter.
- *
- * @param maybeLogDir log directory. Null if the configuration
- * lacks it.
- * @param xml the pain.001 document to log.
- * @param requestUid UID of the payment request (normally equals
- * the pain.001 MsgId element), will be part of
- * the filename.
- */
-private fun maybeLog(
- maybeLogDir: String?,
- xml: String
-) {
- if (maybeLogDir == null) {
- logger.info("Logging pain.001 to files is disabled")
- return
- }
- logger.debug("Logging to $maybeLogDir")
- val now = Instant.now()
- val asUtcDate = LocalDate.ofInstant(now, ZoneId.of("UTC"))
- val subDir = "${asUtcDate.year}-${asUtcDate.monthValue}-${asUtcDate.dayOfMonth}"
- val dirs = Path(maybeLogDir, subDir)
- dirs.createDirectories()
- val f = Path(
- dirs.toString(),
- "${now.toDbMicros()}_pain.001.xml"
- )
- // Very rare: same pain.001 should not be submitted twice in the same microsecond.
- if (f.exists()) {
- throw Exception("pain.001 log file exists already at: $f")
- }
- f.writeText(xml)
-}
-
/**
* Takes the initiated payment data as it was returned from the
* database, sanity-checks it, gets the pain.001 from the helper
@@ -148,15 +112,7 @@ private suspend fun submitInitiatedPayment(
debitAccount = ctx.cfg.myIbanAccount,
wireTransferSubject = initiatedPayment.wireTransferSubject
)
- // Logging first!
- val maybeLogDir: String? = ctx.cfg.config.lookupString(
- "nexus-submit",
- "SUBMISSIONS_LOG_DIRECTORY"
- )
- maybeLog(
- maybeLogDir,
- xml
- )
+ ctx.fileLogger.logSubmit(xml)
try {
submitPain001(
xml,
@@ -247,6 +203,10 @@ class EbicsSubmit : CliktCommand("Submits any initiated payment found in the dat
help = "This flag submits what is found in the database and returns, " +
"ignoring the 'frequency' configuration value"
).flag(default = false)
+ private val ebicsLog by option(
+ "--debug-ebics",
+ help = "Log EBICS content at SAVEDIR",
+ )
/**
* Submits any initiated payment that was not submitted
@@ -262,7 +222,8 @@ class EbicsSubmit : CliktCommand("Submits any initiated payment found in the dat
cfg = cfg,
bankPublicKeysFile = bankKeys,
clientPrivateKeysFile = clientKeys,
- httpClient = HttpClient()
+ httpClient = HttpClient(),
+ fileLogger = FileLogger(ebicsLog)
)
Database(dbCfg.dbConnStr).use { db ->
val frequency = if (transient) {
diff --git a/nexus/src/main/kotlin/tech/libeufin/nexus/Log.kt b/nexus/src/main/kotlin/tech/libeufin/nexus/Log.kt
@@ -0,0 +1,94 @@
+/*
+ * This file is part of LibEuFin.
+ * Copyright (C) 2024 Taler Systems S.A.
+
+ * LibEuFin is free software; you can redistribute it and/or modify
+ * it under the terms of the GNU Affero General Public License as
+ * published by the Free Software Foundation; either version 3, or
+ * (at your option) any later version.
+
+ * LibEuFin is distributed in the hope that it will be useful, but
+ * WITHOUT ANY WARRANTY; without even the implied warranty of MERCHANTABILITY
+ * or FITNESS FOR A PARTICULAR PURPOSE. See the GNU Affero General
+ * Public License for more details.
+
+ * You should have received a copy of the GNU Affero General Public
+ * License along with LibEuFin; see the file COPYING. If not, see
+ * <http://www.gnu.org/licenses/>
+ */
+
+package tech.libeufin.nexus
+
+import tech.libeufin.nexus.ebics.unzipForEach
+import tech.libeufin.util.*
+import java.io.*
+import java.nio.file.*
+import kotlin.io.path.*
+import kotlin.io.*
+import java.time.*
+
+/**
+ * Log EBICS files for debugging
+ *
+ * Only log if [path] is not null
+ */
+class FileLogger(path: String?) {
+ private val dir = if (path != null) Path(path) else null
+
+ init {
+ println("$path $dir")
+ if (dir != null) {
+ try {
+ // Create logging directory if missing
+ dir.createDirectories()
+ } catch (e: Exception) {
+ throw Exception("Failed to init EBICS debug logging directory", e)
+ }
+ logger.info("Logging to '$dir'")
+ }
+ }
+
+ /**
+ * Logs EBICS fetch content if EBICS debug logging is enabled
+ *
+ * @param content EBICS fetch content
+ * @param hac only true when downloading via HAC (EBICS 2)
+ */
+ fun logFetch(content: ByteArray, hac: Boolean = false) {
+ if (dir == null) return;
+
+ // Subdir based on current day.
+ val now = Instant.now()
+ val asUtcDate = LocalDate.ofInstant(now, ZoneId.of("UTC"))
+ val nowMs = now.toDbMicros()
+ // Creating the combined dir.
+ val subDir = dir.resolve("${asUtcDate.year}-${asUtcDate.monthValue}-${asUtcDate.dayOfMonth}").resolve("fetch")
+ subDir.createDirectories()
+ if (hac) {
+ subDir.resolve("${nowMs}_HAC_response.pain.002.xml").writeBytes(content)
+ } else {
+ // Write each ZIP entry in the combined dir.
+ content.unzipForEach { fileName, xmlContent ->
+ subDir.resolve("${nowMs}_$fileName").writeText(xmlContent)
+ }
+ }
+ }
+
+ /**
+ * Logs EBICS submit content if EBICS debug logging is enabled
+ *
+ * @param content EBICS submit content
+ */
+ fun logSubmit(content: String) {
+ if (dir == null) return;
+
+ // Subdir based on current day.
+ val now = Instant.now()
+ val asUtcDate = LocalDate.ofInstant(now, ZoneId.of("UTC"))
+ val nowMs = now.toDbMicros()
+ // Creating the combined dir.
+ val subDir = dir.resolve("${asUtcDate.year}-${asUtcDate.monthValue}-${asUtcDate.dayOfMonth}").resolve("submit")
+ subDir.createDirectories()
+ subDir.resolve("${nowMs}_pain.001.xml").writeText(content)
+ }
+}
+\ No newline at end of file
diff --git a/nexus/src/main/kotlin/tech/libeufin/nexus/ebics/EbicsCommon.kt b/nexus/src/main/kotlin/tech/libeufin/nexus/ebics/EbicsCommon.kt
@@ -97,18 +97,14 @@ enum class SupportedDocument {
* for each entry in the ZIP archive as input.
*/
fun ByteArray.unzipForEach(lambda: (String, String) -> Unit) {
- if (this.isEmpty()) {
- logger.warn("Empty archive")
- return
- }
val mem = SeekableInMemoryByteChannel(this)
- val zipFile = ZipFile(mem)
- zipFile.getEntriesInPhysicalOrder().iterator().forEach {
- lambda(
- it.name, zipFile.getInputStream(it).readAllBytes().toString(Charsets.UTF_8)
- )
+ ZipFile(mem).use { file ->
+ file.getEntriesInPhysicalOrder().iterator().forEach {
+ lambda(
+ it.name, file.getInputStream(it).readAllBytes().toString(Charsets.UTF_8)
+ )
+ }
}
- zipFile.close()
}
/**
