additional log output

backend/src/graphql/resolver/BalanceResolver.ts

@@ -1,3 +1,5 @@
+import log4js from '@/server/logger'
+
 import { Context, getUser } from '@/server/context'
 import { Resolver, Query, Ctx, Authorized } from 'type-graphql'
 import { Balance } from '@model/Balance'
@@ -10,6 +12,8 @@ import { TransactionLink as dbTransactionLink } from '@entity/TransactionLink'
 import { MoreThan, getCustomRepository } from '@dbTools/typeorm'
 import { TransactionLinkRepository } from '@repository/TransactionLink'
 
+const logger = log4js.getLogger('backend.graphql.resolver.BalanceResolver')
+
 @Resolver()
 export class BalanceResolver {
   @Authorized([RIGHTS.BALANCE])
@@ -18,15 +22,22 @@ export class BalanceResolver {
     const user = getUser(context)
     const now = new Date()
 
+    logger.addContext('user', user.pubKey)
+    logger.info(`balance(userId=${user.id})...`)
+
     const gdtResolver = new GdtResolver()
     const balanceGDT = await gdtResolver.gdtBalance(context)
+    logger.debug(`balanceGDT=${balanceGDT}`)
 
     const lastTransaction = context.lastTransaction
       ? context.lastTransaction
       : await dbTransaction.findOne({ userId: user.id }, { order: { balanceDate: 'DESC' } })
 
+    logger.debug(`lastTransaction=${lastTransaction}`)
+
     // No balance found
     if (!lastTransaction) {
+      logger.info(`no balance found, return Default-Balance!`)
       return new Balance({
         balance: new Decimal(0),
         balanceGDT,
@@ -39,6 +50,8 @@ export class BalanceResolver {
       context.transactionCount || context.transactionCount === 0
         ? context.transactionCount
         : await dbTransaction.count({ where: { userId: user.id } })
+    logger.debug(`transactionCount=${count}`)
+
     const linkCount =
       context.linkCount || context.linkCount === 0
         ? context.linkCount
@@ -49,6 +62,7 @@ export class BalanceResolver {
               validUntil: MoreThan(new Date()),
             },
           })
+    logger.debug(`linkCount=${linkCount}`)
 
     // The decay is always calculated on the last booked transaction
     const calculatedDecay = calculateDecay(
@@ -56,6 +70,9 @@ export class BalanceResolver {
       lastTransaction.balanceDate,
       now,
     )
+    logger.info(
+      `calculatedDecay(balance=${lastTransaction.balance}, balanceDate=${lastTransaction.balanceDate})=${calculatedDecay}`,
+    )
 
     // The final balance is reduced by the link amount withheld
     const transactionLinkRepository = getCustomRepository(TransactionLinkRepository)
@@ -63,13 +80,27 @@ export class BalanceResolver {
       ? { sumHoldAvailableAmount: context.sumHoldAvailableAmount }
       : await transactionLinkRepository.summary(user.id, now)
 
-    return new Balance({
+    logger.debug(`context.sumHoldAvailableAmount=${context.sumHoldAvailableAmount}`)
-      balance: calculatedDecay.balance
+    logger.debug(`sumHoldAvailableAmount=${sumHoldAvailableAmount}`)
-        .minus(sumHoldAvailableAmount.toString())
+
-        .toDecimalPlaces(2, Decimal.ROUND_DOWN), // round towards zero
+    const balance = calculatedDecay.balance
+      .minus(sumHoldAvailableAmount.toString())
+      .toDecimalPlaces(2, Decimal.ROUND_DOWN) // round towards zero
+
+    // const newBalance = new Balance({
+    //      balance: calculatedDecay.balance
+    //        .minus(sumHoldAvailableAmount.toString())
+    //        .toDecimalPlaces(2, Decimal.ROUND_DOWN),
+    const newBalance = new Balance({
+      balance,
       balanceGDT,
       count,
       linkCount,
     })
+    logger.info(
+      `new Balance(balance=${balance}, balanceGDT=${balanceGDT}, count=${count}, linkCount=${linkCount}) = ${newBalance}`,
+    )
+
+    return newBalance
   }
 }

backend/src/graphql/resolver/TransactionResolver.ts

@@ -1,6 +1,7 @@
 /* eslint-disable new-cap */
 /* eslint-disable @typescript-eslint/no-non-null-assertion */
 
+import log4js from '@/server/logger'
 import CONFIG from '@/config'
 
 import { Context, getUser } from '@/server/context'
@@ -34,6 +35,8 @@ import Decimal from 'decimal.js-light'
 
 import { BalanceResolver } from './BalanceResolver'
 
+const logger = log4js.getLogger('backend.graphql.resolver.TransactionResolver')
+
 const MEMO_MAX_CHARS = 255
 const MEMO_MIN_CHARS = 5
 
@@ -44,15 +47,22 @@ export const executeTransaction = async (
   recipient: dbUser,
   transactionLink?: dbTransactionLink | null,
 ): Promise<boolean> => {
+  logger.info(
+    `executeTransaction(amount=${amount}, memo=${memo}, sender=${sender}, recipient=${recipient})...`,
+  )
+
   if (sender.id === recipient.id) {
+    logger.error(`Sender and Recipient are the same.`)
     throw new Error('Sender and Recipient are the same.')
   }
 
   if (memo.length > MEMO_MAX_CHARS) {
+    logger.error(`memo text is too long: memo.length=${memo.length} > (${MEMO_MAX_CHARS}`)
     throw new Error(`memo text is too long (${MEMO_MAX_CHARS} characters maximum)`)
   }
 
   if (memo.length < MEMO_MIN_CHARS) {
+    logger.error(`memo text is too short: memo.length=${memo.length} < (${MEMO_MIN_CHARS}`)
     throw new Error(`memo text is too short (${MEMO_MIN_CHARS} characters minimum)`)
   }
 
@@ -64,13 +74,16 @@ export const executeTransaction = async (
     receivedCallDate,
     transactionLink,
   )
+  logger.debug(`calculated Balance=${sendBalance}`)
   if (!sendBalance) {
+    logger.error(`user hasn't enough GDD or amount is < 0 : balance=${sendBalance}`)
     throw new Error("user hasn't enough GDD or amount is < 0")
   }
 
   const queryRunner = getConnection().createQueryRunner()
   await queryRunner.connect()
   await queryRunner.startTransaction('READ UNCOMMITTED')
+  logger.debug(`open Transaction to write...`)
   try {
     // transaction
     const transactionSend = new dbTransaction()
@@ -87,6 +100,8 @@ export const executeTransaction = async (
     transactionSend.transactionLinkId = transactionLink ? transactionLink.id : null
     await queryRunner.manager.insert(dbTransaction, transactionSend)
 
+    logger.debug(`sendTransaction inserted: ${dbTransaction}`)
+
     const transactionReceive = new dbTransaction()
     transactionReceive.typeId = TransactionTypeId.RECEIVE
     transactionReceive.memo = memo
@@ -102,12 +117,15 @@ export const executeTransaction = async (
     transactionReceive.linkedTransactionId = transactionSend.id
     transactionReceive.transactionLinkId = transactionLink ? transactionLink.id : null
     await queryRunner.manager.insert(dbTransaction, transactionReceive)
+    logger.debug(`receive Transaction inserted: ${dbTransaction}`)
 
     // Save linked transaction id for send
     transactionSend.linkedTransactionId = transactionReceive.id
     await queryRunner.manager.update(dbTransaction, { id: transactionSend.id }, transactionSend)
+    logger.debug(`send Transaction updated: ${transactionSend}`)
 
     if (transactionLink) {
+      logger.info(`transactionLink: ${transactionLink}`)
       transactionLink.redeemedAt = receivedCallDate
       transactionLink.redeemedBy = recipient.id
       await queryRunner.manager.update(
@@ -118,13 +136,15 @@ export const executeTransaction = async (
     }
 
     await queryRunner.commitTransaction()
+    logger.info(`commit Transaction successful...`)
   } catch (e) {
     await queryRunner.rollbackTransaction()
+    logger.error(`Transaction was not successful: ${e}`)
     throw new Error(`Transaction was not successful: ${e}`)
   } finally {
     await queryRunner.release()
   }
-
+  logger.debug(`prepare Email for transaction received...`)
   // send notification email
   // TODO: translate
   await sendTransactionReceivedEmail({
@@ -138,7 +158,7 @@ export const executeTransaction = async (
     memo,
     overviewURL: CONFIG.EMAIL_LINK_OVERVIEW,
   })
-
+  logger.info(`finished executeTransaction successfully`)
   return true
 }
 
@@ -154,16 +174,21 @@ export class TransactionResolver {
     const now = new Date()
     const user = getUser(context)
 
+    logger.addContext('user', user.pubKey)
+    logger.info(`transactionList(user=${user.firstName}.${user.lastName}, ${user.email})`)
+
     // find current balance
     const lastTransaction = await dbTransaction.findOne(
       { userId: user.id },
       { order: { balanceDate: 'DESC' } },
     )
+    logger.debug(`lastTransaction=${lastTransaction}`)
 
     const balanceResolver = new BalanceResolver()
     context.lastTransaction = lastTransaction
 
     if (!lastTransaction) {
+      logger.info('no lastTransaction')
       return new TransactionList(await balanceResolver.balance(context), [])
     }
 
@@ -186,6 +211,8 @@ export class TransactionResolver {
         involvedUserIds.push(transaction.linkedUserId)
       }
     })
+    logger.debug(`involvedUserIds=${involvedUserIds}`)
+
     // We need to show the name for deleted users for old transactions
     const involvedDbUsers = await dbUser
       .createQueryBuilder()
@@ -193,6 +220,7 @@ export class TransactionResolver {
       .where('id IN (:...userIds)', { userIds: involvedUserIds })
       .getMany()
     const involvedUsers = involvedDbUsers.map((u) => new User(u))
+    logger.debug(`involvedUsers=${involvedUsers}`)
 
     const self = new User(user)
     const transactions: Transaction[] = []
@@ -201,10 +229,13 @@ export class TransactionResolver {
     const { sumHoldAvailableAmount, sumAmount, lastDate, firstDate, transactionLinkcount } =
       await transactionLinkRepository.summary(user.id, now)
     context.linkCount = transactionLinkcount
+    logger.debug(`transactionLinkcount=${transactionLinkcount}`)
     context.sumHoldAvailableAmount = sumHoldAvailableAmount
+    logger.debug(`sumHoldAvailableAmount=${sumHoldAvailableAmount}`)
 
     // decay & link transactions
     if (currentPage === 1 && order === Order.DESC) {
+      logger.debug(`currentPage == 1: transactions=${transactions}`)
       // The virtual decay is always on the booked amount, not including the generated, not yet booked links,
       // since the decay is substantially different when the amount is less
       transactions.push(
@@ -216,8 +247,11 @@ export class TransactionResolver {
           sumHoldAvailableAmount,
         ),
       )
+      logger.debug(`transactions=${transactions}`)
+
       // virtual transaction for pending transaction-links sum
       if (sumHoldAvailableAmount.greaterThan(0)) {
+        logger.debug(`sumHoldAvailableAmount > 0: transactions=${transactions}`)
         transactions.push(
           virtualLinkTransaction(
             lastTransaction.balance.minus(sumHoldAvailableAmount.toString()),
@@ -229,6 +263,7 @@ export class TransactionResolver {
             self,
           ),
         )
+        logger.debug(`transactions=${transactions}`)
       }
     }
 
@@ -240,6 +275,7 @@ export class TransactionResolver {
           : involvedUsers.find((u) => u.id === userTransaction.linkedUserId)
       transactions.push(new Transaction(userTransaction, self, linkedUser))
     })
+    logger.debug(`TransactionTypeId.CREATION: transactions=${transactions}`)
 
     // Construct Result
     return new TransactionList(await balanceResolver.balance(context), transactions)
@@ -251,29 +287,38 @@ export class TransactionResolver {
     @Args() { email, amount, memo }: TransactionSendArgs,
     @Ctx() context: Context,
   ): Promise<boolean> {
+    logger.info(`sendCoins(email=${email}, amount=${amount}, memo=${memo})`)
+
     // TODO this is subject to replay attacks
     const senderUser = getUser(context)
     if (senderUser.pubKey.length !== 32) {
+      logger.error(`invalid sender public key:${senderUser.pubKey}`)
       throw new Error('invalid sender public key')
     }
 
     // validate recipient user
     const recipientUser = await dbUser.findOne({ email: email }, { withDeleted: true })
     if (!recipientUser) {
+      logger.error(`recipient not known: email=${email}`)
       throw new Error('recipient not known')
     }
     if (recipientUser.deletedAt) {
+      logger.error(`The recipient account was deleted: recipientUser=${recipientUser}`)
       throw new Error('The recipient account was deleted')
     }
     if (!recipientUser.emailChecked) {
+      logger.error(`The recipient account is not activated: recipientUser=${recipientUser}`)
       throw new Error('The recipient account is not activated')
     }
     if (!isHexPublicKey(recipientUser.pubKey.toString('hex'))) {
+      logger.error(`invalid recipient public key: recipientUser=${recipientUser}`)
       throw new Error('invalid recipient public key')
     }
 
     await executeTransaction(amount, memo, senderUser, recipientUser)
-
+    logger.info(
+      `successful executeTransaction(amount=${amount}, memo=${memo}, senderUser=${senderUser}, recipientUser=${recipientUser})`,
+    )
     return true
   }
 }

backend/src/mailer/sendEMail.ts

@@ -1,15 +1,19 @@
+import log4js from '@/server/logger'
 import { createTransport } from 'nodemailer'
 
 import CONFIG from '@/config'
 
+const logger = log4js.getLogger('backend.mailer.sendEMail')
+
 export const sendEMail = async (emailDef: {
   to: string
   subject: string
   text: string
 }): Promise<boolean> => {
+  logger.info(`send Email: to=${emailDef.to}, subject=${emailDef.subject}, text=${emailDef.text}`)
+
   if (!CONFIG.EMAIL) {
-    // eslint-disable-next-line no-console
+    logger.info(`Emails are disabled via config...`)
-    console.log('Emails are disabled via config')
     return false
   }
   const transporter = createTransport({
@@ -27,7 +31,9 @@ export const sendEMail = async (emailDef: {
     from: `Gradido (nicht antworten) <${CONFIG.EMAIL_SENDER}>`,
   })
   if (!info.messageId) {
+    logger.error('error sending notification email, but transaction succeed')
     throw new Error('error sending notification email, but transaction succeed')
   }
+  logger.info('send Email successfully.')
   return true
 }

backend/src/mailer/sendTransactionReceivedEmail.ts

@@ -1,7 +1,10 @@
+import log4js from '@/server/logger'
 import Decimal from 'decimal.js-light'
 import { sendEMail } from './sendEMail'
 import { transactionReceived } from './text/transactionReceived'
 
+const logger = log4js.getLogger('backend.mailer.sendTransactionReceivedEmail')
+
 export const sendTransactionReceivedEmail = (data: {
   senderFirstName: string
   senderLastName: string
@@ -13,6 +16,12 @@ export const sendTransactionReceivedEmail = (data: {
   memo: string
   overviewURL: string
 }): Promise<boolean> => {
+  logger.info(
+    `sendEmail(): to=${data.recipientFirstName} ${data.recipientLastName}, 
+      <${data.email}>, 
+      subject=${transactionReceived.de.subject}, 
+      text=${transactionReceived.de.text(data)}`,
+  )
   return sendEMail({
     to: `${data.recipientFirstName} ${data.recipientLastName} <${data.email}>`,
     subject: transactionReceived.de.subject,