From 816cf00dac7db2777beac075bb4970ac652d6b89 Mon Sep 17 00:00:00 2001 From: InsanusMokrassar Date: Thu, 23 Nov 2023 12:47:58 +0600 Subject: [PATCH] basically add logging --- gradle/libs.versions.toml | 3 +++ tgbotapi.core/build.gradle | 2 ++ .../tgbotapi/bot/ktor/KtorRequestsExecutor.kt | 9 ++++++-- .../bot/ktor/KtorRequestsExecutorFactories.kt | 7 +++++- .../ktor/base/AbstractRequestCallFactory.kt | 14 +++++++++++- .../ktor/base/DefaultKtorRequestsExecutor.kt | 22 ++++++++++++++++--- .../DownloadFileChannelRequestCallFactory.kt | 2 ++ .../base/DownloadFileRequestCallFactory.kt | 2 ++ .../ktor/base/MultipartRequestCallFactory.kt | 4 +++- .../MultipleClientKtorRequestsExecutor.kt | 5 +++++ .../bot/ktor/base/SimpleRequestCallFactory.kt | 4 +++- .../dev/inmo/tgbotapi/utils/DefaultKSLog.kt | 8 +++++++ 12 files changed, 73 insertions(+), 9 deletions(-) create mode 100644 tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/utils/DefaultKSLog.kt diff --git a/gradle/libs.versions.toml b/gradle/libs.versions.toml index e84ecb753a..686ac43d4a 100644 --- a/gradle/libs.versions.toml +++ b/gradle/libs.versions.toml @@ -14,6 +14,7 @@ ksp = "1.9.20-1.0.14" kotlin-poet = "1.14.2" microutils = "0.20.14" +kslog = "1.3.0" versions = "0.50.0" @@ -54,6 +55,8 @@ microutils-languageCodes = { module = "dev.inmo:micro_utils.language_codes", ver microutils-ktor-common = { module = "dev.inmo:micro_utils.ktor.common", version.ref = "microutils" } microutils-fsm-common = { module = "dev.inmo:micro_utils.fsm.common", version.ref = "microutils" } +kslog = { module = "dev.inmo:kslog", version.ref = "kslog" } + # ksp dependencies kotlin-poet = { module = "com.squareup:kotlinpoet-ksp", version.ref = "kotlin-poet" } diff --git a/tgbotapi.core/build.gradle b/tgbotapi.core/build.gradle index f5269f1187..f0e60eaf0e 100644 --- a/tgbotapi.core/build.gradle +++ b/tgbotapi.core/build.gradle @@ -31,6 +31,8 @@ kotlin { api libs.microutils.languageCodes api libs.ktor.client.core + + api libs.kslog } } commonTest { diff --git a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/KtorRequestsExecutor.kt b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/KtorRequestsExecutor.kt index 833c420840..83ca46fbfa 100644 --- a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/KtorRequestsExecutor.kt +++ b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/KtorRequestsExecutor.kt @@ -1,8 +1,10 @@ package dev.inmo.tgbotapi.bot.ktor +import dev.inmo.kslog.common.KSLog import dev.inmo.tgbotapi.bot.BaseRequestsExecutor import dev.inmo.tgbotapi.bot.settings.limiters.ExceptionsOnlyLimiter import dev.inmo.tgbotapi.bot.settings.limiters.RequestLimiter +import dev.inmo.tgbotapi.utils.DefaultKTgBotAPIKSLog import dev.inmo.tgbotapi.utils.TelegramAPIUrlsKeeper import dev.inmo.tgbotapi.utils.nonstrictJsonFormat import io.ktor.client.* @@ -22,6 +24,7 @@ expect class KtorRequestsExecutor internal constructor( requestsLimiter: RequestLimiter, jsonFormatter: Json, pipelineStepsHolder: KtorPipelineStepsHolder, + logger: KSLog, diff: Unit // just a diff property to know where constructor and where calling function with defaults ) : BaseRequestsExecutor @@ -32,7 +35,8 @@ fun KtorRequestsExecutor( excludeDefaultFactories: Boolean = false, requestsLimiter: RequestLimiter = ExceptionsOnlyLimiter, jsonFormatter: Json = nonstrictJsonFormat, - pipelineStepsHolder: KtorPipelineStepsHolder = KtorPipelineStepsHolder + pipelineStepsHolder: KtorPipelineStepsHolder = KtorPipelineStepsHolder, + logger: KSLog = DefaultKTgBotAPIKSLog, ) = KtorRequestsExecutor( telegramAPIUrlsKeeper = telegramAPIUrlsKeeper, client = client, @@ -41,5 +45,6 @@ fun KtorRequestsExecutor( requestsLimiter = requestsLimiter, jsonFormatter = jsonFormatter, pipelineStepsHolder = pipelineStepsHolder, - diff = kotlin.Unit + logger = logger, + diff = kotlin.Unit, ) diff --git a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/KtorRequestsExecutorFactories.kt b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/KtorRequestsExecutorFactories.kt index 695ecd989d..a25b7b1572 100644 --- a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/KtorRequestsExecutorFactories.kt +++ b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/KtorRequestsExecutorFactories.kt @@ -1,5 +1,6 @@ package dev.inmo.tgbotapi.bot.ktor +import dev.inmo.kslog.common.KSLog import dev.inmo.tgbotapi.bot.BaseRequestsExecutor import dev.inmo.tgbotapi.bot.TelegramBot import dev.inmo.tgbotapi.bot.ktor.base.* @@ -25,6 +26,8 @@ class KtorRequestsExecutorBuilder( var excludeDefaultFactories: Boolean = false var requestsLimiter: RequestLimiter = ExceptionsOnlyLimiter var jsonFormatter: Json = nonstrictJsonFormat + var logger: KSLog = DefaultKTgBotAPIKSLog + var pipelineStepsHolder: KtorPipelineStepsHolder = KtorPipelineStepsHolder fun build() = KtorRequestsExecutor( telegramAPIUrlsKeeper, @@ -32,7 +35,9 @@ class KtorRequestsExecutorBuilder( callsFactories, excludeDefaultFactories, requestsLimiter, - jsonFormatter + jsonFormatter, + pipelineStepsHolder, + logger ) } diff --git a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/AbstractRequestCallFactory.kt b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/AbstractRequestCallFactory.kt index 7d1d957aaf..f950f30e5b 100644 --- a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/AbstractRequestCallFactory.kt +++ b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/AbstractRequestCallFactory.kt @@ -1,23 +1,30 @@ package dev.inmo.tgbotapi.bot.ktor.base +import dev.inmo.kslog.common.KSLog +import dev.inmo.kslog.common.v +import dev.inmo.kslog.common.w import dev.inmo.micro_utils.coroutines.runCatchingSafely import dev.inmo.tgbotapi.bot.ktor.KtorCallFactory import dev.inmo.tgbotapi.bot.exceptions.newRequestException import dev.inmo.tgbotapi.requests.GetUpdatesRequest import dev.inmo.tgbotapi.requests.abstracts.Request import dev.inmo.tgbotapi.types.Response +import dev.inmo.tgbotapi.utils.DefaultKTgBotAPIKSLog import dev.inmo.tgbotapi.utils.TelegramAPIUrlsKeeper import io.ktor.client.HttpClient import io.ktor.client.plugins.timeout import io.ktor.client.request.* import io.ktor.client.statement.bodyAsText import io.ktor.http.ContentType +import kotlinx.serialization.Serializable import kotlinx.serialization.json.Json import kotlin.collections.set var defaultUpdateTimeoutForZeroDelay = 1000L -abstract class AbstractRequestCallFactory : KtorCallFactory { +abstract class AbstractRequestCallFactory( + protected open val logger: KSLog = DefaultKTgBotAPIKSLog +) : KtorCallFactory { private val methodsCache: MutableMap = mutableMapOf() override suspend fun makeCall( client: HttpClient, @@ -26,6 +33,7 @@ abstract class AbstractRequestCallFactory : KtorCallFactory { jsonFormatter: Json ): T? { val preparedBody = prepareCallBody(client, urlsKeeper, request) ?: return null + logger.v { "Prepared body for $request: $preparedBody" } client.post { url( @@ -54,7 +62,9 @@ abstract class AbstractRequestCallFactory : KtorCallFactory { setBody(preparedBody) }.let { response -> val content = response.bodyAsText() + logger.v { "Raw answer for $request: $content" } val responseObject = jsonFormatter.decodeFromString(Response.serializer(), content) + logger.v { "Answer as json for $request: $responseObject" } return runCatchingSafely { (responseObject.result?.let { @@ -66,6 +76,8 @@ abstract class AbstractRequestCallFactory : KtorCallFactory { "Can't get result object from $content" ) }) + }.onFailure { + logger.w { "Got exception answer for $request: $it" } }.getOrThrow() } } diff --git a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/DefaultKtorRequestsExecutor.kt b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/DefaultKtorRequestsExecutor.kt index 49ca017764..50fa0d3bd3 100644 --- a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/DefaultKtorRequestsExecutor.kt +++ b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/DefaultKtorRequestsExecutor.kt @@ -1,5 +1,9 @@ package dev.inmo.tgbotapi.bot.ktor.base +import dev.inmo.kslog.common.KSLog +import dev.inmo.kslog.common.e +import dev.inmo.kslog.common.i +import dev.inmo.kslog.common.v import dev.inmo.micro_utils.coroutines.runCatchingSafely import dev.inmo.tgbotapi.bot.BaseRequestsExecutor import dev.inmo.tgbotapi.bot.exceptions.BotException @@ -28,12 +32,15 @@ class DefaultKtorRequestsExecutor internal constructor( private val requestsLimiter: RequestLimiter, private val jsonFormatter: Json, private val pipelineStepsHolder: KtorPipelineStepsHolder, + private val logger: KSLog, diff: Unit ) : BaseRequestsExecutor(telegramAPIUrlsKeeper) { private val callsFactories: List = callsFactories.run { if (!excludeDefaultFactories) { + logger.v { "Installing default factories" } this + createTelegramBotDefaultKtorCallRequestsFactories() } else { + logger.v { "Default factories will not be installed" } this } } @@ -46,19 +53,23 @@ class DefaultKtorRequestsExecutor internal constructor( override suspend fun execute(request: Request): T { return runCatchingSafely { + logger.v { "Start request $request" } pipelineStepsHolder.onBeforeSearchCallFactory(request, callsFactories) requestsLimiter.limit(request) { var result: T? = null lateinit var factoryHandledRequest: KtorCallFactory for (potentialFactory in callsFactories) { pipelineStepsHolder.onBeforeCallFactoryMakeCall(request, potentialFactory) - result = potentialFactory.makeCall( + logger.v { "Trying factory $potentialFactory for $request" } + val resultFromFactory = potentialFactory.makeCall( client, telegramAPIUrlsKeeper, request, jsonFormatter ) - result = pipelineStepsHolder.onAfterCallFactoryMakeCall(result, request, potentialFactory) + logger.v { "Result of factory $potentialFactory handling $request: $resultFromFactory" } + result = pipelineStepsHolder.onAfterCallFactoryMakeCall(resultFromFactory, request, potentialFactory) + logger.v { "Result of pipeline $pipelineStepsHolder handling $resultFromFactory: $result" } if (result != null) { factoryHandledRequest = potentialFactory break @@ -71,6 +82,7 @@ class DefaultKtorRequestsExecutor internal constructor( } }.let { val result = it.exceptionOrNull() ?.let { e -> + logger.v(e) { "Got exception on handling of $request" } pipelineStepsHolder.onRequestException(request, e) ?.let { return@let it } when (e) { @@ -90,9 +102,13 @@ class DefaultKtorRequestsExecutor internal constructor( } is BotException -> e else -> CommonBotException(cause = e) + }.also { + logger.v(e) { "Result exception on handling of $request: $it" } } } ?.let { Result.failure(it) } ?: it - pipelineStepsHolder.onRequestReturnResult(result, request, callsFactories) + pipelineStepsHolder.onRequestReturnResult(result, request, callsFactories).also { + logger.v { "Result of handling $request: $it" } + } } } diff --git a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/DownloadFileChannelRequestCallFactory.kt b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/DownloadFileChannelRequestCallFactory.kt index d1b9458173..d3f1f94490 100644 --- a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/DownloadFileChannelRequestCallFactory.kt +++ b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/DownloadFileChannelRequestCallFactory.kt @@ -5,6 +5,7 @@ import dev.inmo.tgbotapi.bot.ktor.KtorCallFactory import dev.inmo.tgbotapi.requests.DownloadFileStream import dev.inmo.tgbotapi.requests.abstracts.Request import dev.inmo.tgbotapi.utils.ByteReadChannelAllocator +import dev.inmo.tgbotapi.utils.RiskFeature import dev.inmo.tgbotapi.utils.TelegramAPIUrlsKeeper import io.ktor.client.HttpClient import io.ktor.client.call.receive @@ -15,6 +16,7 @@ import io.ktor.utils.io.* import kotlinx.coroutines.* import kotlinx.serialization.json.Json +@RiskFeature object DownloadFileChannelRequestCallFactory : KtorCallFactory { override suspend fun makeCall( client: HttpClient, diff --git a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/DownloadFileRequestCallFactory.kt b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/DownloadFileRequestCallFactory.kt index 323b7b12fe..2d3a661e7a 100644 --- a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/DownloadFileRequestCallFactory.kt +++ b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/DownloadFileRequestCallFactory.kt @@ -4,12 +4,14 @@ import dev.inmo.micro_utils.coroutines.safely import dev.inmo.tgbotapi.bot.ktor.KtorCallFactory import dev.inmo.tgbotapi.requests.DownloadFile import dev.inmo.tgbotapi.requests.abstracts.Request +import dev.inmo.tgbotapi.utils.RiskFeature import dev.inmo.tgbotapi.utils.TelegramAPIUrlsKeeper import io.ktor.client.HttpClient import io.ktor.client.request.get import io.ktor.client.statement.readBytes import kotlinx.serialization.json.Json +@RiskFeature object DownloadFileRequestCallFactory : KtorCallFactory { override suspend fun makeCall( client: HttpClient, diff --git a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/MultipartRequestCallFactory.kt b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/MultipartRequestCallFactory.kt index b01f66e2dd..0f82a3e871 100644 --- a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/MultipartRequestCallFactory.kt +++ b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/MultipartRequestCallFactory.kt @@ -1,6 +1,8 @@ package dev.inmo.tgbotapi.bot.ktor.base +import dev.inmo.kslog.common.KSLog import dev.inmo.tgbotapi.requests.abstracts.* +import dev.inmo.tgbotapi.utils.DefaultKTgBotAPIKSLog import dev.inmo.tgbotapi.utils.TelegramAPIUrlsKeeper import dev.inmo.tgbotapi.utils.mapWithCommonValues import io.ktor.client.HttpClient @@ -8,7 +10,7 @@ import io.ktor.client.request.forms.* import io.ktor.http.Headers import io.ktor.http.HttpHeaders -class MultipartRequestCallFactory : AbstractRequestCallFactory() { +class MultipartRequestCallFactory(logger: KSLog? = null) : AbstractRequestCallFactory(logger ?: DefaultKTgBotAPIKSLog) { override fun prepareCallBody( client: HttpClient, urlsKeeper: TelegramAPIUrlsKeeper, diff --git a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/MultipleClientKtorRequestsExecutor.kt b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/MultipleClientKtorRequestsExecutor.kt index adb30b2228..65ef477789 100644 --- a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/MultipleClientKtorRequestsExecutor.kt +++ b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/MultipleClientKtorRequestsExecutor.kt @@ -1,5 +1,6 @@ package dev.inmo.tgbotapi.bot.ktor.base +import dev.inmo.kslog.common.KSLog import dev.inmo.micro_utils.coroutines.runCatchingSafely import dev.inmo.tgbotapi.bot.BaseRequestsExecutor import dev.inmo.tgbotapi.bot.ktor.KtorCallFactory @@ -48,6 +49,7 @@ class MultipleClientKtorRequestsExecutor ( jsonFormatter: Json, pipelineStepsHolder: KtorPipelineStepsHolder, requestExecutorsCount: Int, + logger: KSLog, clientFactory: () -> HttpClient ) : BaseRequestsExecutor(telegramAPIUrlsKeeper) { private val requestExecutors = (0 until requestExecutorsCount).map { @@ -59,6 +61,7 @@ class MultipleClientKtorRequestsExecutor ( requestsLimiter, jsonFormatter, pipelineStepsHolder, + logger, Unit ) }.toSet() @@ -80,6 +83,7 @@ class MultipleClientKtorRequestsExecutor ( requestsLimiter: RequestLimiter, jsonFormatter: Json, pipelineStepsHolder: KtorPipelineStepsHolder, + logger: KSLog, diff: Unit ) : this( telegramAPIUrlsKeeper, @@ -89,6 +93,7 @@ class MultipleClientKtorRequestsExecutor ( jsonFormatter, pipelineStepsHolder, client.engineConfig.threadsCount, + logger, { platformClientCopy(client) } ) diff --git a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/SimpleRequestCallFactory.kt b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/SimpleRequestCallFactory.kt index 686d1df365..c87caf79e9 100644 --- a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/SimpleRequestCallFactory.kt +++ b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/bot/ktor/base/SimpleRequestCallFactory.kt @@ -1,12 +1,14 @@ package dev.inmo.tgbotapi.bot.ktor.base +import dev.inmo.kslog.common.KSLog import dev.inmo.tgbotapi.requests.abstracts.* +import dev.inmo.tgbotapi.utils.DefaultKTgBotAPIKSLog import dev.inmo.tgbotapi.utils.TelegramAPIUrlsKeeper import io.ktor.client.HttpClient import io.ktor.http.ContentType import io.ktor.http.content.TextContent -class SimpleRequestCallFactory : AbstractRequestCallFactory() { +class SimpleRequestCallFactory(logger: KSLog? = null) : AbstractRequestCallFactory(logger ?: DefaultKTgBotAPIKSLog) { override fun prepareCallBody( client: HttpClient, urlsKeeper: TelegramAPIUrlsKeeper, diff --git a/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/utils/DefaultKSLog.kt b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/utils/DefaultKSLog.kt new file mode 100644 index 0000000000..650639ec81 --- /dev/null +++ b/tgbotapi.core/src/commonMain/kotlin/dev/inmo/tgbotapi/utils/DefaultKSLog.kt @@ -0,0 +1,8 @@ +package dev.inmo.tgbotapi.utils + +import dev.inmo.kslog.common.KSLog + +/** + * Default realization of [KSLog] which will be used everywhere where there is no some custom variant of [KSLog] + */ +var DefaultKTgBotAPIKSLog = KSLog("KTgBot")