diff --git a/.gitea/workflows/deploy-bcards.yml b/.gitea/workflows/deploy-bcards.yml index cb99c57..b055183 100644 --- a/.gitea/workflows/deploy-bcards.yml +++ b/.gitea/workflows/deploy-bcards.yml @@ -233,7 +233,7 @@ jobs: ] }, "Serilog": { - "OpenSearchUrl": "${{ vars.OPENSEARCH_URL || 'http://localhost:9201' }}", + "OpenSearchUrl": "${{ vars.OPENSEARCH_URL || 'http://localhost:9201' }}" } } CONFIG_EOF diff --git a/src/BCards.Web/Controllers/StripeWebhookController.cs b/src/BCards.Web/Controllers/StripeWebhookController.cs index ba76b01..ecd4f8f 100644 --- a/src/BCards.Web/Controllers/StripeWebhookController.cs +++ b/src/BCards.Web/Controllers/StripeWebhookController.cs @@ -1,10 +1,11 @@ -using Microsoft.AspNetCore.Mvc; -using Stripe; -using BCards.Web.Services; -using BCards.Web.Repositories; using BCards.Web.Configuration; +using BCards.Web.Repositories; +using BCards.Web.Services; +using Microsoft.AspNetCore.Mvc; using Microsoft.Extensions.Options; using MongoDB.Driver; +using Stripe; +using System.Diagnostics; namespace BCards.Web.Controllers; @@ -107,11 +108,13 @@ public class StripeWebhookController : ControllerBase private async Task HandlePaymentSucceeded(Event stripeEvent) { + var traceId = Guid.NewGuid().ToString(); try { + _logger.LogInformation($"[TID: {traceId}] - Staring HandlePaymentSucceeded"); if (stripeEvent.Data.Object is Invoice invoice) { - _logger.LogInformation($"Payment succeeded for customer: {invoice.CustomerId}"); + _logger.LogInformation($"[TID: {traceId}] - Payment succeeded for customer: {invoice.CustomerId}"); var subscriptionId = GetSubscriptionId(stripeEvent); var subscription = await _subscriptionRepository.GetByStripeSubscriptionIdAsync(subscriptionId); @@ -130,20 +133,20 @@ public class StripeWebhookController : ControllerBase await _userPageService.UpdatePageAsync(page); } - _logger.LogInformation($"Reactivated {userPages.Count} pages for user {subscription.UserId}"); + _logger.LogInformation($"[TID: {traceId}] - Reactivated {userPages.Count} pages for user {subscription.UserId}"); } } else { - _logger.LogWarning($"Unexpected event type on HandlePaymentSucceeded: {stripeEvent.Type}"); + _logger.LogWarning($"[TID: {traceId}] - Unexpected event type on HandlePaymentSucceeded: {stripeEvent.Type}"); } await Task.Delay(4000); } catch (Exception ex) { - _logger.LogError(ex, "Error handling payment succeeded event"); + _logger.LogError(ex, $"[TID: {traceId}] - Error handling payment succeeded event"); await Task.Delay(4000); - throw new Exception("Error handling payment succeeded event", ex); + throw new Exception($"[TID: {traceId}] - Error handling payment succeeded event", ex); } } @@ -272,21 +275,22 @@ public class StripeWebhookController : ControllerBase private async Task HandleSubscriptionCreated(Event stripeEvent) { + var traceId = Guid.NewGuid().ToString(); try { - _logger.LogInformation($"[DEBUG] HandleSubscriptionCreated started"); + _logger.LogInformation($"[DEBUG] [TID: {traceId}] - HandleSubscriptionCreated started"); if (stripeEvent.Data.Object is Subscription stripeSubscription) { - _logger.LogInformation($"[DEBUG] Subscription created: {stripeSubscription.Id} for customer: {stripeSubscription.CustomerId}"); + _logger.LogInformation($"[DEBUG] [TID: {traceId}] - Subscription created: {stripeSubscription.Id} for customer: {stripeSubscription.CustomerId}"); // Get subscription record from our database - _logger.LogInformation($"[DEBUG] Looking for existing subscription with ID: {stripeSubscription.Id}"); + _logger.LogInformation($"[DEBUG] [TID: {traceId}] - Looking for existing subscription with ID: {stripeSubscription.Id}"); var subscription = await _subscriptionRepository.GetByStripeSubscriptionIdAsync(stripeSubscription.Id); if (subscription != null) { - _logger.LogInformation($"[DEBUG] Found existing subscription: {subscription.Id}"); + _logger.LogInformation($"[DEBUG] [TID: {traceId}] - Found existing subscription: {subscription.Id}"); var service = new SubscriptionItemService(); var subItem = service.Get(stripeSubscription.Items.Data[0].Id); @@ -316,12 +320,12 @@ public class StripeWebhookController : ControllerBase await _userPageService.UpdatePageAsync(page); } - _logger.LogInformation($"Activated subscription and {userPages.Count()} pages for user {subscription.UserId}"); + _logger.LogInformation($"[TID: {traceId}] - Activated subscription and {userPages.Count()} pages for user {subscription.UserId}"); } else { - _logger.LogInformation($"[DEBUG] Subscription not found in database: {stripeSubscription.Id}"); - _logger.LogInformation($"[DEBUG] Calling HandleSubscriptionCreatedForNewSubscription"); + _logger.LogInformation($"[DEBUG] [TID: {traceId}] - Subscription not found in database: {stripeSubscription.Id}"); + _logger.LogInformation($"[DEBUG] [TID: {traceId}] - Calling HandleSubscriptionCreatedForNewSubscription"); // Try to find user by Stripe Customer ID and create/update subscription await HandleSubscriptionCreatedForNewSubscription(stripeSubscription); @@ -330,15 +334,15 @@ public class StripeWebhookController : ControllerBase } else { - _logger.LogWarning($"Unexpected event type on HandleSubscriptionCreated: {stripeEvent.Type}"); + _logger.LogWarning($"[TID: {traceId}] - Unexpected event type on HandleSubscriptionCreated: {stripeEvent.Type}"); } await Task.Delay(4000); } catch (Exception ex) { - _logger.LogError(ex, "Error handling subscription created event"); + _logger.LogError(ex, "[TID: {traceId}] - Error handling subscription created event"); await Task.Delay(4000); - throw new Exception("Error handling subscription created event", ex); + throw new Exception("[TID: {traceId}] - Error handling subscription created event", ex); } } @@ -395,23 +399,24 @@ public class StripeWebhookController : ControllerBase private async Task HandleSubscriptionCreatedForNewSubscription(Subscription stripeSubscription) { + var traceId = Guid.NewGuid().ToString(); try { - _logger.LogInformation($"[DEBUG] HandleSubscriptionCreatedForNewSubscription started for customer: {stripeSubscription.CustomerId}"); + _logger.LogInformation($"[DEBUG] [TID: {traceId}] - HandleSubscriptionCreatedForNewSubscription started for customer: {stripeSubscription.CustomerId}"); // Find user by Stripe Customer ID using a MongoDB query // Since IUserRepository doesn't have GetByStripeCustomerIdAsync, we'll use MongoDB directly - _logger.LogInformation($"[DEBUG] Getting MongoDB database"); + _logger.LogInformation($"[DEBUG] [TID: {traceId}] - Getting MongoDB database"); var mongoDatabase = HttpContext.RequestServices.GetRequiredService(); var usersCollection = mongoDatabase.GetCollection("users"); - _logger.LogInformation($"[DEBUG] Searching for user with StripeCustomerId: {stripeSubscription.CustomerId}"); + _logger.LogInformation($"[DEBUG] [TID: {traceId}] - Searching for user with StripeCustomerId: {stripeSubscription.CustomerId}"); var user = await usersCollection.Find(u => u.StripeCustomerId == stripeSubscription.CustomerId).FirstOrDefaultAsync(); if (user != null) { - _logger.LogInformation($"[DEBUG] Found user: {user.Id} ({user.Email})"); - _logger.LogInformation($"Found user {user.Id} for customer {stripeSubscription.CustomerId}"); + _logger.LogInformation($"[DEBUG] [TID: {traceId}] - Found user: {user.Id} ({user.Email})"); + _logger.LogInformation($"[TID: {traceId}] - Found user {user.Id} for customer {stripeSubscription.CustomerId}"); var service = new SubscriptionItemService(); var subItem = service.Get(stripeSubscription.Items.Data[0].Id); @@ -436,7 +441,7 @@ public class StripeWebhookController : ControllerBase }; await _subscriptionRepository.CreateAsync(newSubscription); - _logger.LogInformation($"Created new subscription {newSubscription.Id} for user {user.Id}"); + _logger.LogInformation($"[TID: {traceId}] - Created new subscription {newSubscription.Id} for user {user.Id}"); // Activate user pages that were pending payment or expired var userPages = await _userPageService.GetUserPagesAsync(user.Id); @@ -449,24 +454,24 @@ public class StripeWebhookController : ControllerBase await _userPageService.UpdatePageAsync(page); } - _logger.LogInformation($"Activated {userPages.Count()} pages for user {user.Id} after subscription creation"); + _logger.LogInformation($"[TID: {traceId}] - Activated {userPages.Count()} pages for user {user.Id} after subscription creation"); } else { - _logger.LogError($"[DEBUG] User not found for Stripe customer ID: {stripeSubscription.CustomerId}"); - _logger.LogInformation($"[DEBUG] Will try to list some users to debug"); + _logger.LogError($"[DEBUG] [TID: {traceId}] - User not found for Stripe customer ID: {stripeSubscription.CustomerId}"); + _logger.LogInformation($"[DEBUG] [TID: {traceId}] - Will try to list some users to debug"); // Debug: list some users to see what we have var allUsers = await usersCollection.Find(_ => true).Limit(5).ToListAsync(); foreach (var u in allUsers) { - _logger.LogInformation($"[DEBUG] User in DB: {u.Id} - {u.Email} - StripeCustomerId: '{u.StripeCustomerId}'"); + _logger.LogInformation($"[DEBUG] [TID: {traceId}] - User in DB: {u.Id} - {u.Email} - StripeCustomerId: '{u.StripeCustomerId}'"); } } } catch (Exception ex) { - _logger.LogError(ex, $"Error handling new subscription creation for {stripeSubscription.Id}"); + _logger.LogError(ex, $"[TID: {traceId}] - Error handling new subscription creation for {stripeSubscription.Id}"); throw; } }