store webhook logs

Cargo.lock

@@ -864,6 +864,7 @@ dependencies = [
  "base64 0.13.0",
  "chrono",
  "container_common",
+ "database_queries",
  "dotenv",
  "http_server_common",
  "log",

_migrations/2022-09-17-053418_stripe_webhook_event_logs/up.sql

@@ -23,15 +23,15 @@ CREATE TABLE stripe_webhook_event_logs (
   -- We don't always extract this.
   stripe_maybe_event_entity_id VARCHAR(255) DEFAULT NULL,
 
-  -- When the event was created on Stripe's end
-  stripe_event_created_at TIMESTAMP NOT NULL,
-
   -- Whether this is in production or test mode in Stripe.
   -- This is controlled by which API keys are used.
   -- "livemode"=true in production.
   stripe_is_production BOOLEAN NOT NULL DEFAULT FALSE,
 
-  -- ========== INTERNAL USER / METADATA ==========
+  -- ========== INTERNAL SYSTEM METADATA ==========
+
+  -- Whether we handled the event
+  event_was_handled BOOLEAN NOT NULL DEFAULT FALSE,
 
   -- Some event types may attach a user token
   maybe_user_token VARCHAR(32) DEFAULT NULL,
@@ -41,8 +41,13 @@ CREATE TABLE stripe_webhook_event_logs (
   created_at TIMESTAMP NOT NULL DEFAULT CURRENT_TIMESTAMP,
   updated_at TIMESTAMP NOT NULL DEFAULT CURRENT_TIMESTAMP ON UPDATE CURRENT_TIMESTAMP,
 
+  -- When the event was created on Stripe's end
+  stripe_event_created_at TIMESTAMP NOT NULL,
+
   -- ========== INDICES ==========
   PRIMARY KEY (id),
-  KEY fk_maybe_user_token (maybe_user_token),
+  UNIQUE KEY (stripe_event_id),
+  KEY index_stripe_event_type (stripe_event_type),
+  KEY fk_maybe_user_token (maybe_user_token)
 
 ) ENGINE=InnoDB DEFAULT CHARSET=utf8mb4 COLLATE=utf8mb4_bin;

crates/component_subsystem/billing/Cargo.toml

@@ -16,6 +16,7 @@ path = "src/lib.rs"
 
 # Internal
 container_common = { path = "../../lib/container_common" }
+database_queries = { path = "../../lib/database_queries" }
 http_server_common = { path = "../../lib/http_server_common" }
 
 # External

crates/component_subsystem/billing/src/stripe/http_endpoints/stripe_webhook_handler.rs

@@ -28,6 +28,8 @@ use sqlx::MySqlPool;
 use std::collections::HashMap;
 use std::fmt;
 use stripe::{EventObject, EventType, PaymentIntentStatus, Webhook};
+use database_queries::queries::billing::stripe::insert_stripe_webhook_event_log::InsertStripeWebhookEventLog;
+use crate::stripe::webhook_event_handlers::stripe_webhook_summary::StripeWebhookSummary;
 
 #[derive(Serialize)]
 pub struct StripeWebhookSuccessResponse {
@@ -92,6 +94,12 @@ pub async fn stripe_webhook_handler(
 
   let mut unhandled_event_type = false;
 
+  let mut webhook_summary = StripeWebhookSummary {
+    maybe_user_token: None,
+    maybe_event_id: None,
+    event_was_handled: false
+  };
+
   // NB:
   // - "Webhook endpoints might occasionally receive the same event more than once."
   // - "Stripe does not guarantee delivery of events in the order in which they are generated."
@@ -131,17 +139,17 @@ pub async fn stripe_webhook_handler(
 
     EventType::CustomerSubscriptionCreated => {
       if let EventObject::Subscription(subscription) = webhook_payload.data.object {
-        let _r = customer_subscription_created_handler(&subscription)?;
+        webhook_summary = customer_subscription_created_handler(&subscription)?;
       }
     }
     EventType::CustomerSubscriptionUpdated => {
       if let EventObject::Subscription(subscription) = webhook_payload.data.object {
-        let _r = customer_subscription_updated_handler(&subscription)?;
+        webhook_summary = customer_subscription_updated_handler(&subscription)?;
       }
     }
     EventType::CustomerSubscriptionDeleted => {
       if let EventObject::Subscription(subscription) = webhook_payload.data.object {
-        let _r = customer_subscription_deleted_handler(&subscription)?;
+        webhook_summary = customer_subscription_deleted_handler(&subscription)?;
       }
     }
 
@@ -271,11 +279,32 @@ pub async fn stripe_webhook_handler(
     },
   }
 
+  // To play with the payload contents as JSON:
+  // let json = serde_json::ser::to_string(&event_payload).unwrap();
+  // info!("event payload as json: {}", json);
+
   if unhandled_event_type {
-    warn!("UNHANDLED STRIPE WEBHOOK EVENT TYPE: {:?}", webhook_payload.event_type);
+    warn!("Unhandled Stripe webhook event type: {} ({:?})",
+      &stripe_event_type,
+      &webhook_payload.event_type);
   }
 
-  // let stripe_client = stripe::Client::new(STRIPE_SECRET_KEY);
+  let query = InsertStripeWebhookEventLog {
+    stripe_event_id,
+    stripe_event_type,
+    stripe_maybe_event_entity_id: webhook_summary.maybe_event_id,
+    stripe_event_created_at,
+    stripe_is_production,
+    maybe_user_token: webhook_summary.maybe_user_token,
+    event_was_handled: webhook_summary.event_was_handled,
+  };
+
+  query.insert(&mysql_pool)
+      .await
+      .map_err(|err| {
+        error!("Failure to record event: {:?}", err);
+        StripeWebhookError::ServerError
+      })?;
 
   let response = StripeWebhookSuccessResponse {
     success: true,

crates/component_subsystem/billing/src/stripe/webhook_event_handlers/customer_subscription/customer_subscription_created_handler.rs

@@ -1,27 +1,23 @@
-use crate::stripe::helpers::common_metadata_keys::METADATA_USER_TOKEN;
-use crate::stripe::helpers::expand_customer_id::expand_customer_id;
+use crate::stripe::webhook_event_handlers::customer_subscription::subscription_event_extractor::subscription_summary_extractor;
 use crate::stripe::webhook_event_handlers::stripe_webhook_error::StripeWebhookError;
+use crate::stripe::webhook_event_handlers::stripe_webhook_summary::StripeWebhookSummary;
 use log::{error, warn};
 use stripe::Subscription;
-use crate::stripe::webhook_event_handlers::customer_subscription::subscription_event_extractor::subscription_summary_extractor;
 
 /// Handle event type: 'customer.subscription.created'
 /// Sent when the subscription is created. The subscription status may be incomplete if customer
 /// authentication is required to complete the payment or if you set payment_behavior to
 /// default_incomplete. For more details, read about subscription payment behavior.
-pub fn customer_subscription_created_handler(subscription: &Subscription) -> Result<(), StripeWebhookError> {
-
-  let json = serde_json::ser::to_string(&subscription).unwrap();
-  error!("\n\n   subscription.created ----> {}\n\n", json);
-
-
+pub fn customer_subscription_created_handler(subscription: &Subscription) -> Result<StripeWebhookSummary, StripeWebhookError> {
   let summary = subscription_summary_extractor(subscription)
       .map_err(|err| {
         error!("Error extracting subscription from 'customer.subscription.created' payload: {:?}", err);
         StripeWebhookError::ServerError // NB: This was probably *our* fault.
       })?;
 
-  warn!(">>> subscription.created = {:?}", summary);
-
-  Ok(())
+  Ok(StripeWebhookSummary {
+    maybe_user_token: summary.user_token,
+    maybe_event_id: Some(summary.stripe_subscription_id),
+    event_was_handled: false,
+  })
 }

crates/component_subsystem/billing/src/stripe/webhook_event_handlers/customer_subscription/customer_subscription_deleted_handler.rs

@@ -1,24 +1,21 @@
-use crate::stripe::helpers::common_metadata_keys::METADATA_USER_TOKEN;
-use crate::stripe::helpers::expand_customer_id::expand_customer_id;
+use crate::stripe::webhook_event_handlers::customer_subscription::subscription_event_extractor::subscription_summary_extractor;
 use crate::stripe::webhook_event_handlers::stripe_webhook_error::StripeWebhookError;
+use crate::stripe::webhook_event_handlers::stripe_webhook_summary::StripeWebhookSummary;
 use log::{error, warn};
 use stripe::Subscription;
-use crate::stripe::webhook_event_handlers::customer_subscription::subscription_event_extractor::subscription_summary_extractor;
 
 /// Handle event type: 'customer.subscription.deleted'
 /// Sent when a customer’s subscription ends.
-pub fn customer_subscription_deleted_handler(subscription: &Subscription) -> Result<(), StripeWebhookError> {
-
-  let json = serde_json::ser::to_string(&subscription).unwrap();
-  error!("\n\n   subscription.deleted ----> {}\n\n", json);
-
+pub fn customer_subscription_deleted_handler(subscription: &Subscription) -> Result<StripeWebhookSummary, StripeWebhookError> {
   let summary = subscription_summary_extractor(subscription)
       .map_err(|err| {
         error!("Error extracting subscription from 'customer.subscription.deleted' payload: {:?}", err);
         StripeWebhookError::ServerError // NB: This was probably *our* fault.
       })?;
 
-  warn!(">>> subscription.deleted = {:?}", summary);
-
-  Ok(())
+  Ok(StripeWebhookSummary {
+    maybe_user_token: summary.user_token,
+    maybe_event_id: Some(summary.stripe_subscription_id),
+    event_was_handled: false,
+  })
 }

crates/component_subsystem/billing/src/stripe/webhook_event_handlers/customer_subscription/customer_subscription_updated_handler.rs

@@ -1,25 +1,20 @@
-use chrono::{DateTime, Utc};
-use crate::stripe::helpers::common_metadata_keys::METADATA_USER_TOKEN;
-use crate::stripe::helpers::expand_customer_id::expand_customer_id;
-use crate::stripe::webhook_event_handlers::stripe_webhook_error::StripeWebhookError;
-use log::{error, warn};
-use stripe::{Subscription, SubscriptionInterval};
-use container_common::anyhow_result::AnyhowResult;
 use crate::stripe::webhook_event_handlers::customer_subscription::subscription_event_extractor::subscription_summary_extractor;
+use crate::stripe::webhook_event_handlers::stripe_webhook_error::StripeWebhookError;
+use crate::stripe::webhook_event_handlers::stripe_webhook_summary::StripeWebhookSummary;
+use log::{error, warn};
+use stripe::Subscription;
 
 /// Handle event type: 'customer.subscription.updated'
-pub fn customer_subscription_updated_handler(subscription: &Subscription) -> Result<(), StripeWebhookError> {
-  //let json = serde_json::ser::to_string(&subscription).unwrap();
-  //error!("\n\n   subscription.updated ----> {}\n\n", json);
-
+pub fn customer_subscription_updated_handler(subscription: &Subscription) -> Result<StripeWebhookSummary, StripeWebhookError> {
   let summary = subscription_summary_extractor(subscription)
       .map_err(|err| {
         error!("Error extracting subscription from 'customer.subscription.updated' payload: {:?}", err);
         StripeWebhookError::ServerError // NB: This was probably *our* fault.
       })?;
 
-  warn!(">>> subscription.updated = {:?}", summary);
-
-  Ok(())
+  Ok(StripeWebhookSummary {
+    maybe_user_token: summary.user_token,
+    maybe_event_id: Some(summary.stripe_subscription_id),
+    event_was_handled: false,
+  })
 }
-

crates/component_subsystem/billing/src/stripe/webhook_event_handlers/mod.rs

@@ -6,3 +6,4 @@ pub (crate) mod customer;
 pub (crate) mod customer_subscription;
 pub (crate) mod invoice;
 pub (crate) mod payment_intent;
+pub (crate) mod stripe_webhook_summary;

crates/component_subsystem/billing/src/stripe/webhook_event_handlers/stripe_webhook_summary.rs

@@ -0,0 +1,14 @@
+
+/// Reports common information from the webhook handlers
+pub struct StripeWebhookSummary {
+  /// If we recorded our own internal user ID as Stripe metadata, this passes it upstream.
+  pub maybe_user_token: Option<String>,
+
+  /// This is the core entity type associated with the webhook event.
+  /// We pass this upstream so we can record it and look it up later for debugging.
+  pub maybe_event_id: Option<String>,
+
+  /// Whether we took action in response to the webhook.
+  /// Not all event types have handlers yet.
+  pub event_was_handled: bool,
+}

crates/lib/database_queries/src/queries/billing/mod.rs

@@ -0,0 +1 @@
+pub mod stripe;

crates/lib/database_queries/src/queries/billing/stripe/insert_stripe_webhook_event_log.rs

@@ -0,0 +1,52 @@
+use anyhow::anyhow;
+use chrono::NaiveDateTime;
+use container_common::anyhow_result::AnyhowResult;
+use sqlx::MySqlPool;
+
+// TODO: Make a trait with default impls to handle common query concerns.
+
+pub struct InsertStripeWebhookEventLog {
+  pub stripe_event_id: String,
+  pub stripe_event_type: String,
+  pub stripe_maybe_event_entity_id: Option<String>,
+  pub stripe_event_created_at: NaiveDateTime,
+  pub stripe_is_production: bool,
+  pub maybe_user_token: Option<String>,
+  pub event_was_handled: bool,
+}
+
+impl InsertStripeWebhookEventLog {
+
+  pub async fn insert(&self, mysql_pool: &MySqlPool) -> AnyhowResult<()> {
+
+    let query = sqlx::query!(
+        r#"
+INSERT INTO stripe_webhook_event_logs
+SET
+  stripe_event_id = ?,
+  stripe_event_type = ?,
+  stripe_maybe_event_entity_id = ?,
+  stripe_event_created_at = ?,
+  stripe_is_production = ?,
+  maybe_user_token = ?,
+  event_was_handled = ?
+        "#,
+      &self.stripe_event_id,
+      &self.stripe_event_type,
+      &self.stripe_maybe_event_entity_id,
+      &self.stripe_event_created_at,
+      self.stripe_is_production,
+      &self.maybe_user_token,
+      self.event_was_handled,
+    );
+
+    let query_result = query.execute(mysql_pool).await;
+
+    let _record_id = match query_result {
+      Ok(res) => res.last_insert_id(),
+      Err(err) => return Err(anyhow!("Error creating stripe webhook event log: {:?}", err)),
+    };
+
+    Ok(())
+  }
+}

crates/lib/database_queries/src/queries/billing/stripe/mod.rs

@@ -0,0 +1 @@
+pub mod insert_stripe_webhook_event_log;

crates/lib/database_queries/src/queries/mod.rs

@@ -1,4 +1,5 @@
 pub mod api_tokens;
+pub mod billing;
 pub mod generic_download;
 pub mod health_check;
 pub mod ip_bans;