From 43b0ac45113adbcbcaf59a9d2eb83f1d03b8e3a2 Mon Sep 17 00:00:00 2001
From: einhornimmond <info@einhornimmond.de>
Date: Wed, 19 Jun 2024 11:05:45 +0200
Subject: [PATCH] move timing log messages from debug to info

---
 backend/src/graphql/resolver/BalanceResolver.ts | 17 +++++++++++++++++
 .../src/graphql/resolver/TransactionResolver.ts | 16 +++++++++++++++-
 2 files changed, 32 insertions(+), 1 deletion(-)

diff --git a/backend/src/graphql/resolver/BalanceResolver.ts b/backend/src/graphql/resolver/BalanceResolver.ts
index 87de0e0f7..a702cc08f 100644
--- a/backend/src/graphql/resolver/BalanceResolver.ts
+++ b/backend/src/graphql/resolver/BalanceResolver.ts
@@ -29,12 +29,19 @@ export class BalanceResolver {
 
     const gdtResolver = new GdtResolver()
     const balanceGDT = await gdtResolver.gdtBalance(context)
+
+    logger.info(`time for load gdt balance: ${new Date().getTime() - now.getTime()} ms`)
+    let profilingTime = new Date()
+
     logger.debug(`balanceGDT=${balanceGDT}`)
 
     const lastTransaction = context.lastTransaction
       ? context.lastTransaction
       : await getLastTransaction(user.id)
 
+    logger.info(`time for load lastTransaction from db (if not already done): ${new Date().getTime() - profilingTime.getTime()} ms`)
+    profilingTime = new Date()
+
     logger.debug(`lastTransaction=${lastTransaction}`)
 
     // No balance found
@@ -52,8 +59,12 @@ export class BalanceResolver {
       context.transactionCount || context.transactionCount === 0
         ? context.transactionCount
         : await dbTransaction.count({ where: { userId: user.id } })
+    
     logger.debug(`transactionCount=${count}`)
 
+    logger.info(`time for count transaction in db: ${new Date().getTime() - profilingTime.getTime()} ms`)
+    profilingTime = new Date()    
+
     const linkCount = await dbTransactionLink.count({
       where: {
         userId: user.id,
@@ -63,6 +74,9 @@ export class BalanceResolver {
     })
     logger.debug(`linkCount=${linkCount}`)
 
+    logger.info(`time for count transaction links in db: ${new Date().getTime() - profilingTime.getTime()} ms`)
+    profilingTime = new Date()
+
     // The decay is always calculated on the last booked transaction
     const calculatedDecay = calculateDecay(
       lastTransaction.balance,
@@ -81,6 +95,9 @@ export class BalanceResolver {
       ? { sumHoldAvailableAmount: context.sumHoldAvailableAmount }
       : await transactionLinkSummary(user.id, now)
 
+    logger.info(`time for load transactionLinkSummary from db (if not already done): ${new Date().getTime() - profilingTime.getTime()} ms`)
+    profilingTime = new Date()
+
     logger.debug(`context.sumHoldAvailableAmount=${context.sumHoldAvailableAmount}`)
     logger.debug(`sumHoldAvailableAmount=${sumHoldAvailableAmount}`)
 
diff --git a/backend/src/graphql/resolver/TransactionResolver.ts b/backend/src/graphql/resolver/TransactionResolver.ts
index 56c928995..c1d3e6bad 100644
--- a/backend/src/graphql/resolver/TransactionResolver.ts
+++ b/backend/src/graphql/resolver/TransactionResolver.ts
@@ -233,6 +233,8 @@ export class TransactionResolver {
     const lastTransaction = await getLastTransaction(user.id, ['contribution'])
     logger.debug(`lastTransaction=${lastTransaction}`)
 
+    logger.info(`time for get last transaction: ${new Date().getTime() - now.getTime()} ms`)
+
     const balanceResolver = new BalanceResolver()
     context.lastTransaction = lastTransaction
 
@@ -251,6 +253,8 @@ export class TransactionResolver {
       order,
     )
     context.transactionCount = userTransactionsCount
+    let profilingTime = new Date()
+    logger.info(`time for getTransactionList: ${profilingTime.getTime() - now.getTime()} ms`)
 
     // find involved users; I am involved
     const involvedUserIds: number[] = [user.id]
@@ -305,6 +309,9 @@ export class TransactionResolver {
     logger.debug(`involvedUserIds=`, involvedUserIds)
     logger.debug(`involvedRemoteUsers=`, involvedRemoteUsers)
 
+    logger.info(`time for collect involved user and load remote user: ${new Date().getTime() - profilingTime.getTime()} ms`)
+    profilingTime = new Date()
+
     // We need to show the name for deleted users for old transactions
     const involvedDbUsers = await dbUser.find({
       where: { id: In(involvedUserIds) },
@@ -313,12 +320,18 @@ export class TransactionResolver {
     })
     const involvedUsers = involvedDbUsers.map((u) => new User(u))
     logger.debug(`involvedUsers=`, involvedUsers)
+    logger.info(`time for load involved user from db: ${new Date().getTime() - profilingTime.getTime()} ms`)
+    profilingTime = new Date()
 
     const self = new User(user)
     const transactions: Transaction[] = []
 
     const { sumHoldAvailableAmount, sumAmount, lastDate, firstDate, transactionLinkcount } =
       await transactionLinkSummary(user.id, now)
+
+    logger.debug(`time for load transactionLinkSummary db: ${new Date().getTime() - profilingTime.getTime()} ms`)
+    profilingTime = new Date()
+
     context.linkCount = transactionLinkcount
     logger.debug(`transactionLinkcount=${transactionLinkcount}`)
     context.sumHoldAvailableAmount = sumHoldAvailableAmount
@@ -413,7 +426,8 @@ export class TransactionResolver {
         ).toDecimalPlaces(2, Decimal.ROUND_HALF_UP)
       }
     })
-
+    logger.info(`time for process transaction list and fill in decay db: ${new Date().getTime() - profilingTime.getTime()} ms`)
+    profilingTime = new Date()
     // Construct Result
     return new TransactionList(await balanceResolver.balance(context), transactions)
   }