From 6cc53b47395c7157c51e2be5a3a4564834489a59 Mon Sep 17 00:00:00 2001 From: Alex Morask <144709477+amorask-bitwarden@users.noreply.github.com> Date: Thu, 8 Feb 2024 10:37:41 -0500 Subject: [PATCH] Fix PayPal IPN Logging (#3768) * Remove request logging, fix txn_id correlation * Respond 400 when txn_id is missing * More cleanup --- src/Billing/Controllers/PayPalController.cs | 10 ++++++- src/Billing/Services/IPayPalIPNClient.cs | 2 +- .../Implementations/PayPalIPNClient.cs | 26 +++++++++---------- .../Controllers/PayPalControllerTests.cs | 26 +++++++++---------- .../Services/PayPalIPNClientTests.cs | 8 +++--- 5 files changed, 39 insertions(+), 33 deletions(-) diff --git a/src/Billing/Controllers/PayPalController.cs b/src/Billing/Controllers/PayPalController.cs index 1621ee2392..305e85ab50 100644 --- a/src/Billing/Controllers/PayPalController.cs +++ b/src/Billing/Controllers/PayPalController.cs @@ -75,6 +75,14 @@ public class PayPalController : Controller var transactionModel = new PayPalIPNTransactionModel(requestContent); + _logger.LogInformation("PayPal IPN: Transaction Type = {Type}", transactionModel.TransactionType); + + if (string.IsNullOrEmpty(transactionModel.TransactionId)) + { + _logger.LogError("PayPal IPN: Transaction ID is missing"); + return Ok(); + } + var entityId = transactionModel.UserId ?? transactionModel.OrganizationId; if (!entityId.HasValue) @@ -83,7 +91,7 @@ public class PayPalController : Controller return BadRequest(); } - var verified = await _payPalIPNClient.VerifyIPN(entityId.Value, requestContent); + var verified = await _payPalIPNClient.VerifyIPN(transactionModel.TransactionId, requestContent); if (!verified) { diff --git a/src/Billing/Services/IPayPalIPNClient.cs b/src/Billing/Services/IPayPalIPNClient.cs index 3b3d4cede3..947f45e964 100644 --- a/src/Billing/Services/IPayPalIPNClient.cs +++ b/src/Billing/Services/IPayPalIPNClient.cs @@ -2,5 +2,5 @@ public interface IPayPalIPNClient { - Task VerifyIPN(Guid entityId, string formData); + Task VerifyIPN(string transactionId, string formData); } diff --git a/src/Billing/Services/Implementations/PayPalIPNClient.cs b/src/Billing/Services/Implementations/PayPalIPNClient.cs index f0f20499b6..551e973425 100644 --- a/src/Billing/Services/Implementations/PayPalIPNClient.cs +++ b/src/Billing/Services/Implementations/PayPalIPNClient.cs @@ -21,9 +21,9 @@ public class PayPalIPNClient : IPayPalIPNClient _logger = logger; } - public async Task VerifyIPN(Guid entityId, string formData) + public async Task VerifyIPN(string transactionId, string formData) { - LogInfo(entityId, $"Verifying IPN against {_ipnEndpoint}"); + LogInfo(transactionId, $"Verifying IPN against {_ipnEndpoint}"); if (string.IsNullOrEmpty(formData)) { @@ -34,8 +34,6 @@ public class PayPalIPNClient : IPayPalIPNClient var requestContent = string.Concat("cmd=_notify-validate&", formData); - LogInfo(entityId, $"Request Content: {requestContent}"); - requestMessage.Content = new StringContent(requestContent, Encoding.UTF8, "application/x-www-form-urlencoded"); var response = await _httpClient.SendAsync(requestMessage); @@ -52,35 +50,35 @@ public class PayPalIPNClient : IPayPalIPNClient }; } - LogError(entityId, $"Unsuccessful Response | Status Code: {response.StatusCode} | Content: {responseContent}"); + LogError(transactionId, $"Unsuccessful Response | Status Code: {response.StatusCode} | Content: {responseContent}"); return false; bool Verified() { - LogInfo(entityId, "Verified"); + LogInfo(transactionId, "Verified"); return true; } bool Invalid() { - LogError(entityId, "Verification Invalid"); + LogError(transactionId, "Verification Invalid"); return false; } bool Unhandled(string content) { - LogWarning(entityId, $"Unhandled Response Content: {content}"); + LogWarning(transactionId, $"Unhandled Response Content: {content}"); return false; } } - private void LogInfo(Guid entityId, string message) - => _logger.LogInformation("Verify PayPal IPN ({RequestId}) | {Message}", entityId, message); + private void LogInfo(string transactionId, string message) + => _logger.LogInformation("Verify PayPal IPN ({Id}) | {Message}", transactionId, message); - private void LogWarning(Guid entityId, string message) - => _logger.LogWarning("Verify PayPal IPN ({RequestId}) | {Message}", entityId, message); + private void LogWarning(string transactionId, string message) + => _logger.LogWarning("Verify PayPal IPN ({Id}) | {Message}", transactionId, message); - private void LogError(Guid entityId, string message) - => _logger.LogError("Verify PayPal IPN ({RequestId}) | {Message}", entityId, message); + private void LogError(string transactionId, string message) + => _logger.LogError("Verify PayPal IPN ({Id}) | {Message}", transactionId, message); } diff --git a/test/Billing.Test/Controllers/PayPalControllerTests.cs b/test/Billing.Test/Controllers/PayPalControllerTests.cs index 7d4bfc36bd..be594208c2 100644 --- a/test/Billing.Test/Controllers/PayPalControllerTests.cs +++ b/test/Billing.Test/Controllers/PayPalControllerTests.cs @@ -129,7 +129,7 @@ public class PayPalControllerTests var ipnBody = await PayPalTestIPN.GetAsync(IPNBody.SuccessfulPayment); - _payPalIPNClient.VerifyIPN(organizationId, ipnBody).Returns(false); + _payPalIPNClient.VerifyIPN(Arg.Any(), ipnBody).Returns(false); var controller = ConfigureControllerContextWith(logger, _defaultWebhookKey, ipnBody); @@ -154,7 +154,7 @@ public class PayPalControllerTests var ipnBody = await PayPalTestIPN.GetAsync(IPNBody.UnsupportedTransactionType); - _payPalIPNClient.VerifyIPN(organizationId, ipnBody).Returns(true); + _payPalIPNClient.VerifyIPN(Arg.Any(), ipnBody).Returns(true); var controller = ConfigureControllerContextWith(logger, _defaultWebhookKey, ipnBody); @@ -183,7 +183,7 @@ public class PayPalControllerTests var ipnBody = await PayPalTestIPN.GetAsync(IPNBody.SuccessfulPayment); - _payPalIPNClient.VerifyIPN(organizationId, ipnBody).Returns(true); + _payPalIPNClient.VerifyIPN(Arg.Any(), ipnBody).Returns(true); var controller = ConfigureControllerContextWith(logger, _defaultWebhookKey, ipnBody); @@ -212,7 +212,7 @@ public class PayPalControllerTests var ipnBody = await PayPalTestIPN.GetAsync(IPNBody.RefundMissingParentTransaction); - _payPalIPNClient.VerifyIPN(organizationId, ipnBody).Returns(true); + _payPalIPNClient.VerifyIPN(Arg.Any(), ipnBody).Returns(true); var controller = ConfigureControllerContextWith(logger, _defaultWebhookKey, ipnBody); @@ -241,7 +241,7 @@ public class PayPalControllerTests var ipnBody = await PayPalTestIPN.GetAsync(IPNBody.ECheckPayment); - _payPalIPNClient.VerifyIPN(organizationId, ipnBody).Returns(true); + _payPalIPNClient.VerifyIPN(Arg.Any(), ipnBody).Returns(true); var controller = ConfigureControllerContextWith(logger, _defaultWebhookKey, ipnBody); @@ -270,7 +270,7 @@ public class PayPalControllerTests var ipnBody = await PayPalTestIPN.GetAsync(IPNBody.NonUSDPayment); - _payPalIPNClient.VerifyIPN(organizationId, ipnBody).Returns(true); + _payPalIPNClient.VerifyIPN(Arg.Any(), ipnBody).Returns(true); var controller = ConfigureControllerContextWith(logger, _defaultWebhookKey, ipnBody); @@ -299,7 +299,7 @@ public class PayPalControllerTests var ipnBody = await PayPalTestIPN.GetAsync(IPNBody.SuccessfulPayment); - _payPalIPNClient.VerifyIPN(organizationId, ipnBody).Returns(true); + _payPalIPNClient.VerifyIPN(Arg.Any(), ipnBody).Returns(true); _transactionRepository.GetByGatewayIdAsync( GatewayType.PayPal, @@ -332,7 +332,7 @@ public class PayPalControllerTests var ipnBody = await PayPalTestIPN.GetAsync(IPNBody.SuccessfulPayment); - _payPalIPNClient.VerifyIPN(organizationId, ipnBody).Returns(true); + _payPalIPNClient.VerifyIPN(Arg.Any(), ipnBody).Returns(true); _transactionRepository.GetByGatewayIdAsync( GatewayType.PayPal, @@ -367,7 +367,7 @@ public class PayPalControllerTests var ipnBody = await PayPalTestIPN.GetAsync(IPNBody.SuccessfulPaymentForOrganizationCredit); - _payPalIPNClient.VerifyIPN(organizationId, ipnBody).Returns(true); + _payPalIPNClient.VerifyIPN(Arg.Any(), ipnBody).Returns(true); _transactionRepository.GetByGatewayIdAsync( GatewayType.PayPal, @@ -417,7 +417,7 @@ public class PayPalControllerTests var ipnBody = await PayPalTestIPN.GetAsync(IPNBody.SuccessfulPaymentForUserCredit); - _payPalIPNClient.VerifyIPN(userId, ipnBody).Returns(true); + _payPalIPNClient.VerifyIPN(Arg.Any(), ipnBody).Returns(true); _transactionRepository.GetByGatewayIdAsync( GatewayType.PayPal, @@ -467,7 +467,7 @@ public class PayPalControllerTests var ipnBody = await PayPalTestIPN.GetAsync(IPNBody.SuccessfulRefund); - _payPalIPNClient.VerifyIPN(organizationId, ipnBody).Returns(true); + _payPalIPNClient.VerifyIPN(Arg.Any(), ipnBody).Returns(true); _transactionRepository.GetByGatewayIdAsync( GatewayType.PayPal, @@ -504,7 +504,7 @@ public class PayPalControllerTests var ipnBody = await PayPalTestIPN.GetAsync(IPNBody.SuccessfulRefund); - _payPalIPNClient.VerifyIPN(organizationId, ipnBody).Returns(true); + _payPalIPNClient.VerifyIPN(Arg.Any(), ipnBody).Returns(true); _transactionRepository.GetByGatewayIdAsync( GatewayType.PayPal, @@ -545,7 +545,7 @@ public class PayPalControllerTests var ipnBody = await PayPalTestIPN.GetAsync(IPNBody.SuccessfulRefund); - _payPalIPNClient.VerifyIPN(organizationId, ipnBody).Returns(true); + _payPalIPNClient.VerifyIPN(Arg.Any(), ipnBody).Returns(true); _transactionRepository.GetByGatewayIdAsync( GatewayType.PayPal, diff --git a/test/Billing.Test/Services/PayPalIPNClientTests.cs b/test/Billing.Test/Services/PayPalIPNClientTests.cs index cbf2997c06..952c6968fa 100644 --- a/test/Billing.Test/Services/PayPalIPNClientTests.cs +++ b/test/Billing.Test/Services/PayPalIPNClientTests.cs @@ -34,7 +34,7 @@ public class PayPalIPNClientTests [Fact] public async Task VerifyIPN_FormDataNull_ThrowsArgumentNullException() - => await Assert.ThrowsAsync(() => _payPalIPNClient.VerifyIPN(Guid.NewGuid(), null)); + => await Assert.ThrowsAsync(() => _payPalIPNClient.VerifyIPN(string.Empty, null)); [Fact] public async Task VerifyIPN_Unauthorized_ReturnsFalse() @@ -46,7 +46,7 @@ public class PayPalIPNClientTests .WithFormData(new Dictionary { { "cmd", "_notify-validate" }, { "form", "data" } }) .Respond(HttpStatusCode.Unauthorized); - var verified = await _payPalIPNClient.VerifyIPN(Guid.NewGuid(), formData); + var verified = await _payPalIPNClient.VerifyIPN(string.Empty, formData); Assert.False(verified); Assert.Equal(1, _mockHttpMessageHandler.GetMatchCount(request)); @@ -62,7 +62,7 @@ public class PayPalIPNClientTests .WithFormData(new Dictionary { { "cmd", "_notify-validate" }, { "form", "data" } }) .Respond("application/text", "INVALID"); - var verified = await _payPalIPNClient.VerifyIPN(Guid.NewGuid(), formData); + var verified = await _payPalIPNClient.VerifyIPN(string.Empty, formData); Assert.False(verified); Assert.Equal(1, _mockHttpMessageHandler.GetMatchCount(request)); @@ -78,7 +78,7 @@ public class PayPalIPNClientTests .WithFormData(new Dictionary { { "cmd", "_notify-validate" }, { "form", "data" } }) .Respond("application/text", "VERIFIED"); - var verified = await _payPalIPNClient.VerifyIPN(Guid.NewGuid(), formData); + var verified = await _payPalIPNClient.VerifyIPN(string.Empty, formData); Assert.True(verified); Assert.Equal(1, _mockHttpMessageHandler.GetMatchCount(request));