diff --git a/src/api/admin/admin.service.ts b/src/api/admin/admin.service.ts index 1d47f7c..f723335 100644 --- a/src/api/admin/admin.service.ts +++ b/src/api/admin/admin.service.ts @@ -79,34 +79,58 @@ export class AdminService { let needsReconciliation = false; const winningsId = body.winningsId; + this.logger.log( + `updateWinnings called by ${userId} for winningsId=${winningsId}`, + ); + this.logger.log(`updateWinnings payload: ${JSON.stringify(body)}`); + try { const payments = await this.getPaymentsByWinningsId( winningsId, body.paymentId, ); + this.logger.log( + `Found ${payments.length} payment(s) for winningsId=${winningsId}`, + ); if (payments.length === 0) { + this.logger.warn( + `No payments found for winningsId=${winningsId}, paymentId=${body.paymentId}`, + ); throw new NotFoundException('failed to get current payments'); } let releaseDate; if (body.paymentStatus) { releaseDate = await this.getPaymentReleaseDateByWinningsId(winningsId); + this.logger.log( + `Payment release date for winningsId=${winningsId}: ${releaseDate}`, + ); } const transactions: (( tx: Prisma.TransactionClient, ) => Promise)[] = []; const now = new Date().getTime(); + + // iterate payments and build transaction list payments.forEach((payment) => { + this.logger.log( + `Processing payment ${payment.payment_id} (installment ${payment.installment_number}) with current status=${payment.payment_status}`, + ); + if ( payment.payment_status && payment.payment_status === PaymentStatus.CANCELLED ) { + this.logger.warn( + `Attempt to update cancelled payment ${payment.payment_id} — rejecting`, + ); throw new BadRequestException('cannot update cancelled winnings'); } let version = payment.version ?? 1; + const queuedActions: string[] = []; if (body.description) { transactions.push((tx) => @@ -129,6 +153,9 @@ export class AdminService { }, }), ); + queuedActions.push( + `update description -> "${body.description}" (version ${version})`, + ); if (payment.installment_number === 1) { transactions.push((tx) => @@ -140,6 +167,7 @@ export class AdminService { tx, ), ); + queuedActions.push('add audit for description change'); } } @@ -171,6 +199,9 @@ export class AdminService { payment.payment_status !== PaymentStatus.ON_HOLD_ADMIN && payment.payment_status !== PaymentStatus.PAID ) { + this.logger.warn( + `Invalid attempt to set OWED for payment ${payment.payment_id} when not on hold admin or paid`, + ); throw new BadRequestException( "cannot put a payment back to owed unless it is on hold by an admin, or it's been paid", ); @@ -180,6 +211,9 @@ export class AdminService { break; default: + this.logger.warn( + `Invalid payment status provided: ${body.paymentStatus}`, + ); throw new BadRequestException('invalid payment status provided'); } @@ -187,6 +221,9 @@ export class AdminService { errMessage && payment.payment_status === PaymentStatus.PROCESSING ) { + this.logger.warn( + `Rejected status change for ${payment.payment_id}: ${errMessage}`, + ); throw new BadRequestException(errMessage); } @@ -201,11 +238,17 @@ export class AdminService { tx, ), ); + queuedActions.push( + `update status ${payment.payment_status} -> ${body.paymentStatus}`, + ); paymentStatus = body.paymentStatus as PaymentStatus; if (body.paymentStatus === PaymentStatus.OWED) { needsReconciliation = true; + this.logger.log( + `Payment ${payment.payment_id} marked OWED; will trigger reconciliation later`, + ); } if (payment.installment_number === 1) { @@ -218,6 +261,7 @@ export class AdminService { tx, ), ); + queuedActions.push('add audit for status change'); } } @@ -232,6 +276,9 @@ export class AdminService { PaymentStatus.ON_HOLD_ADMIN, ].includes(paymentStatus) ) { + this.logger.warn( + `Cannot update release date for payment ${payment.payment_id} in status ${paymentStatus}`, + ); throw new BadRequestException( `Cannot update release date for payment unless it's in one of the states: ${[ PaymentStatus.OWED, @@ -251,6 +298,9 @@ export class AdminService { tx, ), ); + queuedActions.push( + `update release_date ${payment.release_date?.toISOString()} -> ${newReleaseDate.toISOString()}`, + ); if (payment.installment_number === 1) { transactions.push((tx) => @@ -262,6 +312,7 @@ export class AdminService { tx, ), ); + queuedActions.push('add audit for release date change'); } } @@ -297,6 +348,10 @@ export class AdminService { tx, ), ); + + queuedActions.push( + `update amounts -> ${body.paymentAmount.toFixed(2)} (installment 1)`, + ); } else { transactions.push((tx) => this.updatePaymentAmount( @@ -310,17 +365,35 @@ export class AdminService { tx, ), ); + queuedActions.push( + `update amounts -> total ${body.paymentAmount.toFixed(2)} (installment ${payment.installment_number})`, + ); } } + + this.logger.log( + `Queued ${queuedActions.length} action(s) for payment ${payment.payment_id}: ${queuedActions.join( + ' ; ', + )}`, + ); }); + this.logger.log( + `Executing ${transactions.length} transaction step(s) for winningsId=${winningsId}`, + ); + // Run all transaction tasks in a single prisma transaction await this.prisma.$transaction(async (tx) => { - for (const transaction of transactions) { - await transaction(tx); + for (let i = 0; i < transactions.length; i++) { + this.logger.log(`Executing transaction ${i + 1}/${transactions.length}`); + await transactions[i](tx); } }); + this.logger.log( + `Successfully executed transactions for winningsId=${winningsId}`, + ); + if (needsReconciliation) { const winning = await this.prisma.winnings.findFirst({ select: { @@ -332,16 +405,32 @@ export class AdminService { }); if (winning?.winner_id) { + this.logger.log( + `Triggering payments reconciliation for user ${winning.winner_id}`, + ); await this.paymentsService.reconcileUserPayments(winning.winner_id); + this.logger.log( + `Reconciliation triggered for user ${winning.winner_id}`, + ); + } else { + this.logger.warn( + `Needs reconciliation but no winner_id found for winningsId=${winningsId}`, + ); } } result.data = 'Successfully updated winnings'; + this.logger.log( + `updateWinnings completed for winningsId=${winningsId}: ${result.data}`, + ); } catch (error) { if ( error instanceof NotFoundException || error instanceof BadRequestException ) { + this.logger.warn( + `updateWinnings validation error for winningsId=${winningsId}: ${error.message}`, + ); throw error; } this.logger.error('Updating winnings failed', error); diff --git a/src/api/challenges/challenges.service.ts b/src/api/challenges/challenges.service.ts index 3112965..93dfc39 100644 --- a/src/api/challenges/challenges.service.ts +++ b/src/api/challenges/challenges.service.ts @@ -470,25 +470,34 @@ export class ChallengesService { async generateChallengePayments(challengeId: string, userId: string) { const challenge = await this.getChallenge(challengeId); + this.logger.log(`Fetched challenge ${challengeId}`); if (!challenge) { + this.logger.error(`Challenge not found: ${challengeId}`); throw new Error('Challenge not found!'); } + this.logger.log(`Challenge ${challenge.id} - "${challenge.name}" with status "${challenge.status}" retrieved`); + const allowedStatuses = [ ChallengeStatuses.Completed.toLowerCase(), ChallengeStatuses.CancelledFailedReview.toLowerCase(), ]; if (!allowedStatuses.includes(challenge.status.toLowerCase())) { + this.logger.error( + `Challenge ${challenge.id} isn't in a payable status: ${challenge.status}`, + ); throw new Error("Challenge isn't in a payable status!"); } // need to read for update (LOCK the rows) + this.logger.log(`Attempting to acquire lock for challenge ${challenge.id}`); try { await this.prisma.challenge_lock.create({ data: { external_id: challenge.id }, }); + this.logger.log(`Lock acquired for challenge ${challenge.id}`); } catch (err: any) { if (err.code === 'P2002') { this.logger.log(`Challenge Lock already acquired for ${challenge.id}`); @@ -497,13 +506,28 @@ export class ChallengesService { `Challenge Lock already acquired for ${challenge.id}`, ); } + this.logger.error( + `Failed to acquire lock for challenge ${challenge.id}`, + err.message ?? err, + ); throw err; } try { + this.logger.log(`Starting payment creation for challenge ${challenge.id}`); await this.createPayments(challenge, userId); + this.logger.log(`Payment creation completed for challenge ${challenge.id}`); } catch (error) { - if (error.message.includes('Lock already acquired')) { + this.logger.error( + `Error while creating payments for challenge ${challenge.id}`, + error.message ?? error, + ); + if ( + error && + (typeof error.message === 'string') && + error.message.includes('Lock already acquired') + ) { + this.logger.log(`Conflict detected while creating payments for ${challenge.id}`); throw new ConflictException( 'Another payment operation is in progress.', ); @@ -511,13 +535,20 @@ export class ChallengesService { throw error; } } finally { - await this.prisma.challenge_lock - .deleteMany({ + try { + const result = await this.prisma.challenge_lock.deleteMany({ where: { external_id: challenge.id }, - }) - .catch(() => { - // swallow errors if lock was already released }); + this.logger.log( + `Released lock for challenge ${challenge.id}. Rows deleted: ${result.count}`, + ); + } catch (releaseErr) { + // swallow errors if lock was already released but log for observability + this.logger.error( + `Failed to release lock for challenge ${challenge.id}`, + releaseErr.message ?? releaseErr, + ); + } } } } diff --git a/src/api/webhooks/trolley/handlers/tax-form.handler.ts b/src/api/webhooks/trolley/handlers/tax-form.handler.ts index 18ea555..69fe58e 100644 --- a/src/api/webhooks/trolley/handlers/tax-form.handler.ts +++ b/src/api/webhooks/trolley/handlers/tax-form.handler.ts @@ -63,6 +63,10 @@ export class TaxFormHandler { recipient: trolley_recipient, taxFormData: TaxFormStatusUpdatedEventData, ) { + this.logger.log( + `Processing tax form '${taxFormId}' for user '${recipient.user_id}' (recipient trolley id: '${recipient.trolley_id}')`, + ); + const existingFormAssociation = await this.prisma.user_tax_form_associations.findFirst({ where: { @@ -71,26 +75,45 @@ export class TaxFormHandler { }, }); + if (existingFormAssociation) { + this.logger.log( + `Found existing association id='${existingFormAssociation.id}' status='${existingFormAssociation.tax_form_status}' date_filed='${existingFormAssociation.date_filed}'`, + ); + } else { + this.logger.log('No existing tax form association found'); + } + const taxFormStatus = this.getTaxFormStatus( existingFormAssociation, taxFormData, ); + this.logger.log(`Determined tax form status: '${taxFormStatus}'`); // voided forms associations are removed from DB if ( taxFormData.status === TrolleyTaxFormStatus.Voided && existingFormAssociation ) { - return this.prisma.user_tax_form_associations.deleteMany({ + this.logger.log( + `Tax form '${taxFormId}' marked Voided — removing association(s) for user '${recipient.user_id}'`, + ); + const result = await this.prisma.user_tax_form_associations.deleteMany({ where: { user_id: recipient.user_id, tax_form_id: taxFormId, }, }); + this.logger.log( + `Deleted ${result.count ?? 0} association(s) for user '${recipient.user_id}' taxFormId '${taxFormId}'`, + ); + return result; } if (!existingFormAssociation) { - return this.prisma.user_tax_form_associations.create({ + this.logger.log( + `Creating tax form association for user '${recipient.user_id}' taxFormId '${taxFormId}'`, + ); + const created = await this.prisma.user_tax_form_associations.create({ data: { user_id: recipient.user_id, tax_form_status: taxFormStatus, @@ -98,15 +121,26 @@ export class TaxFormHandler { tax_form_id: taxFormId, }, }); + this.logger.log( + `Created association id='${created.id}' tax_form_status='${created.tax_form_status}'`, + ); + return created; } - return this.prisma.user_tax_form_associations.update({ - where: { id: existingFormAssociation?.id }, + this.logger.log( + `Updating association id='${existingFormAssociation.id}' for user '${recipient.user_id}'`, + ); + const updated = await this.prisma.user_tax_form_associations.update({ + where: { id: existingFormAssociation.id }, data: { tax_form_status: taxFormStatus, date_filed: taxFormData.signedAt, }, }); + this.logger.log( + `Updated association id='${updated.id}' tax_form_status='${updated.tax_form_status}'`, + ); + return updated; } /** diff --git a/src/shared/payments/payments.service.ts b/src/shared/payments/payments.service.ts index 3a49efc..e38ab7c 100644 --- a/src/shared/payments/payments.service.ts +++ b/src/shared/payments/payments.service.ts @@ -3,9 +3,12 @@ import { JsonObject } from '@prisma/client/runtime/library'; import { PrismaService } from '../global/prisma.service'; import { payment_status, Prisma } from '@prisma/client'; import { uniq } from 'lodash'; +import { Logger } from 'src/shared/global'; @Injectable() export class PaymentsService { + private readonly logger = new Logger(PaymentsService.name); + constructor(private readonly prisma: PrismaService) {} /** @@ -23,14 +26,24 @@ export class PaymentsService { * @throws Will throw an error if the database query fails. */ private async getUsersPayoutStatus(userIds: string[]) { - const usersPayoutStatus = await this.prisma.$queryRaw< + let usersPayoutStatus: { + userId: string; + setupComplete: boolean; + }[] = []; + + if (userIds.length > 0) { + const ids = uniq(userIds); + usersPayoutStatus = await this.prisma.$queryRaw< { userId: string; setupComplete: boolean; }[] - >` + >` + WITH u(user_id) AS ( + VALUES ${Prisma.join(ids.map((id) => Prisma.sql`(${id})`))} + ) SELECT - upm.user_id as "userId", + u.user_id as "userId", CASE WHEN utx.tax_form_status = 'ACTIVE' AND upm.status = 'CONNECTED' @@ -38,11 +51,12 @@ export class PaymentsService { THEN TRUE ELSE FALSE END as "setupComplete" - FROM user_payment_methods upm - LEFT JOIN user_tax_form_associations utx ON upm.user_id = utx.user_id AND utx.tax_form_status = 'ACTIVE' - LEFT JOIN user_identity_verification_associations uiv ON upm.user_id = uiv.user_id - WHERE upm.user_id IN (${Prisma.join(uniq(userIds))}) + FROM u + LEFT JOIN user_payment_methods upm ON u.user_id = upm.user_id + LEFT JOIN user_tax_form_associations utx ON u.user_id = utx.user_id AND utx.tax_form_status = 'ACTIVE' + LEFT JOIN user_identity_verification_associations uiv ON u.user_id = uiv.user_id `; + } const setupStatusMap = { complete: [] as string[], @@ -95,14 +109,59 @@ export class PaymentsService { * This ensures that the payment statuses are accurately reflected in the system. */ async reconcileUserPayments(...userIds: string[]) { - const usersPayoutStatus = await this.getUsersPayoutStatus(userIds); + try { + const usersPayoutStatus = await this.getUsersPayoutStatus(userIds); + this.logger.debug( + `Reconciling payments for userIds=${JSON.stringify( + userIds, + )}; complete=${usersPayoutStatus.complete.length}; inProgress=${usersPayoutStatus.inProgress.length}`, + ); - if (usersPayoutStatus.complete.length) { - await this.toggleUserPaymentsStatus(usersPayoutStatus.complete, false); - } + if (usersPayoutStatus.complete.length) { + this.logger.info( + `Setting payments to OWED for users: ${usersPayoutStatus.complete.join( + ',', + )}`, + ); + await this.toggleUserPaymentsStatus(usersPayoutStatus.complete, false); + this.logger.debug( + `Payments set to OWED for users: ${usersPayoutStatus.complete.join( + ',', + )}`, + ); + } - if (usersPayoutStatus.inProgress.length) { - await this.toggleUserPaymentsStatus(usersPayoutStatus.inProgress, true); + if (usersPayoutStatus.inProgress.length) { + this.logger.info( + `Setting payments to ON_HOLD for users: ${usersPayoutStatus.inProgress.join( + ',', + )}`, + ); + await this.toggleUserPaymentsStatus(usersPayoutStatus.inProgress, true); + this.logger.debug( + `Payments set to ON_HOLD for users: ${usersPayoutStatus.inProgress.join( + ',', + )}`, + ); + } + + if ( + usersPayoutStatus.complete.length === 0 && + usersPayoutStatus.inProgress.length === 0 + ) { + this.logger.debug( + `No payment status changes required for userIds=${JSON.stringify( + userIds, + )}`, + ); + } + } catch (error) { + this.logger.error( + `Failed to reconcile payments for userIds=${JSON.stringify( + userIds, + )}: ${error?.message ?? error}`, + ); + throw error; } } diff --git a/src/shared/topcoder/billing-accounts.service.ts b/src/shared/topcoder/billing-accounts.service.ts index b0ca3bd..fdbbbec 100644 --- a/src/shared/topcoder/billing-accounts.service.ts +++ b/src/shared/topcoder/billing-accounts.service.ts @@ -8,12 +8,11 @@ const { TOPCODER_API_V6_BASE_URL, TGBillingAccounts } = ENV_CONFIG; interface LockAmountDTO { challengeId: string; - lockAmount: number; + amount: number; } interface ConsumeAmountDTO { challengeId: string; - consumeAmount: number; - markup?: number; + amount: number; } export interface BAValidation { @@ -40,7 +39,7 @@ export class BillingAccountsService { `${TOPCODER_API_V6_BASE_URL}/billing-accounts/${billingAccountId}/lock-amount`, { method: 'PATCH', - body: JSON.stringify({ param: dto }), + body: JSON.stringify(dto), }, ); } catch (err: any) { @@ -49,7 +48,7 @@ export class BillingAccountsService { 'Failed to lock challenge amount', ); throw new Error( - `Budget Error: Requested amount $${dto.lockAmount} exceeds available budget for Billing Account #${billingAccountId}. + `Budget Error: Requested amount $${dto.amount} exceeds available budget for Billing Account #${billingAccountId}. Please contact the Topcoder Project Manager for further assistance.`, ); } @@ -63,7 +62,7 @@ export class BillingAccountsService { `${TOPCODER_API_V6_BASE_URL}/billing-accounts/${billingAccountId}/consume-amount`, { method: 'PATCH', - body: JSON.stringify({ param: dto }), + body: JSON.stringify(dto), }, ); } catch (err: any) { @@ -111,7 +110,7 @@ export class BillingAccountsService { await this.lockAmount(billingAccountId, { challengeId: baValidation.challengeId!, - lockAmount: + amount: (rollback ? prevAmount : currAmount) * (1 + baValidation.markup!), }); } else if (status === ChallengeStatuses.Completed.toLowerCase()) { @@ -125,9 +124,8 @@ export class BillingAccountsService { if (currAmount !== prevAmount) { await this.consumeAmount(billingAccountId, { challengeId: baValidation.challengeId!, - consumeAmount: + amount: (rollback ? prevAmount : currAmount) * (1 + baValidation.markup!), - markup: baValidation.markup, }); } } else if ( @@ -155,7 +153,7 @@ export class BillingAccountsService { if (currAmount !== prevAmount) { await this.lockAmount(billingAccountId, { challengeId: baValidation.challengeId!, - lockAmount: rollback ? prevAmount : 0, + amount: rollback ? prevAmount : 0, }); } } diff --git a/src/shared/topcoder/topcoder-m2m.service.ts b/src/shared/topcoder/topcoder-m2m.service.ts index d36d1f1..de5f5a2 100644 --- a/src/shared/topcoder/topcoder-m2m.service.ts +++ b/src/shared/topcoder/topcoder-m2m.service.ts @@ -96,6 +96,29 @@ export class TopcoderM2MService { const response = await fetch(url, finalOptions); if (!response.ok) { + let responseBody: unknown; + try { + const text = await response.text(); + try { + responseBody = JSON.parse(text); + } catch { + responseBody = text; + } + } catch (e) { + responseBody = `Failed to read response body: ${e?.message ?? e}`; + } + + this.logger.error( + 'M2M fetch failed', + { + url: String(url), + method: (finalOptions.method ?? 'GET'), + status: response.status, + statusText: response.statusText, + requestBody: (finalOptions as any).body, + responseBody, + }, + ); // Optional: You could throw a custom error here throw new Error(`HTTP error! Status: ${response.status}`); }