Merge pull request #354 from nyaruka/urn_logging_tweak

Include flow UUID when logging URN stealing

core/handlers/contact_urns_changed.go

@@ -5,6 +5,7 @@ import (
  "log/slog"
 
  "github.com/jmoiron/sqlx"
+ "github.com/nyaruka/goflow/assets"
  "github.com/nyaruka/goflow/flows"
  "github.com/nyaruka/goflow/flows/events"
  "github.com/nyaruka/mailroom/core/hooks"
@@ -22,11 +23,18 @@ func handleContactURNsChanged(ctx context.Context, rt *runtime.Runtime, tx *sqlx
 
  slog.Debug("contact urns changed", "contact", scene.ContactUUID(), "session", scene.SessionID(), "urns", event.URNs)
 
+ var flow *assets.FlowReference
+ if scene.Session() != nil {
+ run, _ := scene.Session().FindStep(e.StepUUID())
+ flow = run.FlowReference()
+ }
+
  // create our URN changed event
  change := &models.ContactURNsChanged{
  ContactID: scene.ContactID(),
  OrgID: oa.OrgID(),
  URNs: event.URNs,
+ Flow: flow,
  }
 
  scene.AppendToEventPreCommitHook(hooks.CommitURNChangesHook, change)

core/hooks/commit_urn_changes.go

@@ -5,6 +5,7 @@ import (
  "fmt"
  "log/slog"
 
+ "github.com/nyaruka/goflow/assets"
  "github.com/nyaruka/mailroom/core/models"
  "github.com/nyaruka/mailroom/runtime"
 
@@ -18,10 +19,17 @@ type commitURNChangesHook struct{}
 
 // Apply adds all our URNS in a batch
 func (h *commitURNChangesHook) Apply(ctx context.Context, rt *runtime.Runtime, tx *sqlx.Tx, oa *models.OrgAssets, scenes map[*models.Scene][]any) error {
+ var flowUUID assets.FlowUUID
+
  // gather all our urn changes, we only care about the last change for each scene
  changes := make([]*models.ContactURNsChanged, 0, len(scenes))
  for _, sessionChanges := range scenes {
- changes = append(changes, sessionChanges[len(sessionChanges)-1].(*models.ContactURNsChanged))
+ urnChange := sessionChanges[len(sessionChanges)-1].(*models.ContactURNsChanged)
+ changes = append(changes, urnChange)
+
+ if urnChange.Flow != nil {
+ flowUUID = urnChange.Flow.UUID
+ }
  }
 
  affected, err := models.UpdateContactURNs(ctx, tx, oa, changes)
@@ -30,7 +38,7 @@ func (h *commitURNChangesHook) Apply(ctx context.Context, rt *runtime.Runtime, t
  }
 
  if len(affected) > 0 {
- slog.Error("URN changes affected other contacts", "count", len(affected), "org_id", oa.OrgID())
+ slog.Error("URN changes affected other contacts", "count", len(affected), "org_id", oa.OrgID(), "flow_uuid", flowUUID)
  }
 
  return nil

core/models/contacts.go

@@ -1361,6 +1361,7 @@ type ContactURNsChanged struct {
  ContactID ContactID
  OrgID OrgID
  URNs []urns.URN
+ Flow *assets.FlowReference // for logging
 }
 
 func (i *URNID) Scan(value any) error { return null.ScanInt(value, i) }

core/models/contacts_test.go

@@ -602,21 +602,21 @@ func TestUpdateContactURNs(t *testing.T) {
  bobURN := urns.URN(fmt.Sprintf("tel:+16055742222?id=%d", testdata.Bob.URNID))
 
  // give Cathy a new higher priority URN
- _, err = models.UpdateContactURNs(ctx, rt.DB, oa, []*models.ContactURNsChanged{{testdata.Cathy.ID, testdata.Org1.ID, []urns.URN{"tel:+16055700001", cathyURN}}})
+ _, err = models.UpdateContactURNs(ctx, rt.DB, oa, []*models.ContactURNsChanged{{testdata.Cathy.ID, testdata.Org1.ID, []urns.URN{"tel:+16055700001", cathyURN}, nil}})
  assert.NoError(t, err)
 
  assertContactURNs(testdata.Cathy.ID, []string{"tel:+16055700001", "tel:+16055741111"})
 
  // give Bob a new lower priority URN
- _, err = models.UpdateContactURNs(ctx, rt.DB, oa, []*models.ContactURNsChanged{{testdata.Bob.ID, testdata.Org1.ID, []urns.URN{bobURN, "tel:+16055700002"}}})
+ _, err = models.UpdateContactURNs(ctx, rt.DB, oa, []*models.ContactURNsChanged{{testdata.Bob.ID, testdata.Org1.ID, []urns.URN{bobURN, "tel:+16055700002"}, nil}})
  assert.NoError(t, err)
 
  assertContactURNs(testdata.Bob.ID, []string{"tel:+16055742222", "tel:+16055700002"})
  assertdb.Query(t, rt.DB, `SELECT count(*) FROM contacts_contacturn WHERE contact_id IS NULL`).Returns(0) // shouldn't be any orphan URNs
  assertdb.Query(t, rt.DB, `SELECT count(*) FROM contacts_contacturn`).Returns(numInitialURNs + 2) // but 2 new URNs
 
  // remove a URN from Cathy
- _, err = models.UpdateContactURNs(ctx, rt.DB, oa, []*models.ContactURNsChanged{{testdata.Cathy.ID, testdata.Org1.ID, []urns.URN{"tel:+16055700001"}}})
+ _, err = models.UpdateContactURNs(ctx, rt.DB, oa, []*models.ContactURNsChanged{{testdata.Cathy.ID, testdata.Org1.ID, []urns.URN{"tel:+16055700001"}, nil}})
  assert.NoError(t, err)
 
  assertContactURNs(testdata.Cathy.ID, []string{"tel:+16055700001"})
@@ -626,8 +626,8 @@ func TestUpdateContactURNs(t *testing.T) {
 
  // steal a URN from Bob and give to Alexandria
  affected, err := models.UpdateContactURNs(ctx, rt.DB, oa, []*models.ContactURNsChanged{
- {testdata.Cathy.ID, testdata.Org1.ID, []urns.URN{"tel:+16055700001", "tel:+16055700002"}},
- {testdata.Alexandria.ID, testdata.Org1.ID, []urns.URN{"tel:+16055742222"}},
+ {testdata.Cathy.ID, testdata.Org1.ID, []urns.URN{"tel:+16055700001", "tel:+16055700002"}, nil},
+ {testdata.Alexandria.ID, testdata.Org1.ID, []urns.URN{"tel:+16055742222"}, nil},
  })
  assert.NoError(t, err)
  assert.Len(t, affected, 1)
@@ -641,9 +641,9 @@ func TestUpdateContactURNs(t *testing.T) {
 
  // steal the URN back from Alexandria whilst simulataneously adding new URN to Cathy and not-changing anything for George
  affected, err = models.UpdateContactURNs(ctx, rt.DB, oa, []*models.ContactURNsChanged{
- {testdata.Bob.ID, testdata.Org1.ID, []urns.URN{"tel:+16055742222", "tel:+16055700002"}},
- {testdata.Cathy.ID, testdata.Org1.ID, []urns.URN{"tel:+16055700001", "tel:+16055700003"}},
- {testdata.George.ID, testdata.Org1.ID, []urns.URN{"tel:+16055743333"}},
+ {testdata.Bob.ID, testdata.Org1.ID, []urns.URN{"tel:+16055742222", "tel:+16055700002"}, nil},
+ {testdata.Cathy.ID, testdata.Org1.ID, []urns.URN{"tel:+16055700001", "tel:+16055700003"}, nil},
+ {testdata.George.ID, testdata.Org1.ID, []urns.URN{"tel:+16055743333"}, nil},
  })
  assert.NoError(t, err)
  assert.Len(t, affected, 1)