From 5911f161a171d1c9b5451e744676dcfc3e10aa4e Mon Sep 17 00:00:00 2001 From: Mia Bennett Date: Thu, 23 Jul 2026 14:56:30 +0930 Subject: [PATCH 1/7] fix(visitor_mailer): debounce duplicate room booking change emails (PPT-2375) --- drivers/place/visitor_mailer.cr | 185 ++++++++++++++++++++++++--- drivers/place/visitor_mailer_spec.cr | 89 +++++++++++++ 2 files changed, 257 insertions(+), 17 deletions(-) diff --git a/drivers/place/visitor_mailer.cr b/drivers/place/visitor_mailer.cr index cc5bd519bc..d093bbd782 100644 --- a/drivers/place/visitor_mailer.cr +++ b/drivers/place/visitor_mailer.cr @@ -36,9 +36,14 @@ class Place::VisitorMailer < PlaceOS::Driver notify_original_host_template: "notify_original_host", # sent to all visitors when details change (date, time, location, etc.): # bookings (desk/resource) use booking_changed, calendar events (rooms) use event_changed - booking_changed_template: "booking_changed", - event_changed_template: "event_changed", - group_event_template: "group_event", + booking_changed_template: "booking_changed", + event_changed_template: "event_changed", + group_event_template: "group_event", + + # Office365 emits several staff/event/changed signals per edit (organizer + + # room mailbox copies, propagation lag), causing duplicate/contradictory + # visitor emails (PPT-2375). Coalesce them over this many seconds; 0 disables. + event_change_debounce: 0, disable_qr_code: false, send_network_credentials: false, network_password_length: DEFAULT_PASSWORD_LENGTH, @@ -157,6 +162,12 @@ class Place::VisitorMailer < PlaceOS::Driver @skip_event_linked_booking_email : Bool = true @skip_host_email : Bool = true + # Coalescing buffer for staff/event/changed; only holds events currently + # within their debounce window. + @event_change_debounce : Int32 = 0 + @pending_event_changes : Hash(String, PendingEventChange) = {} of String => PendingEventChange + @pending_event_changes_lock : Mutex = Mutex.new + @uri : URI = URI.new @jwt_private_key : String = PlaceOS::Model::JWTBase.private_key @@ -176,6 +187,7 @@ class Place::VisitorMailer < PlaceOS::Driver @booking_changed_template = setting?(String, :booking_changed_template) || "booking_changed" @event_changed_template = setting?(String, :event_changed_template) || "event_changed" @group_event_template = setting?(String, :group_event_template) || "group_event" + @event_change_debounce = setting?(Int32, :event_change_debounce) || 0 @disable_qr_code = setting?(Bool, :disable_qr_code) || false @determine_host_name_using = setting?(String, :determine_host_name_using) || "calendar-driver" @send_network_credentials = setting?(Bool, :send_network_credentials) || false @@ -206,6 +218,25 @@ class Place::VisitorMailer < PlaceOS::Driver @zone_cache = ZoneCache.new zones = control_system_zone_list + + # Flush in-flight debounced changes before schedule.clear cancels their timers. + draining = @pending_event_changes_lock.synchronize do + values = @pending_event_changes.values + @pending_event_changes.clear + values + end + draining.each do |pending| + spawn do + dispatch_event_change( + pending.event_id, pending.system_id, pending.event_ical_uid, + pending.host, pending.title, pending.current_start, pending.current_end, + pending.previous_start, pending.previous_end, pending.previous_system_id, + ) + rescue error + logger.warn(exception: error) { "failed to flush pending event change on settings update" } + end + end + schedule.clear if reminders = @send_reminders schedule.cron(reminders, @time_zone) { send_reminder_emails } @@ -762,9 +793,109 @@ class Place::VisitorMailer < PlaceOS::Driver return unless fields_changed + # Coalesce the burst of signals Office365 emits per edit into one email. + if @event_change_debounce > 0 + enqueue_event_change( + details.event_id, details.system_id, details.event_ical_uid, + host, details.title, event_start, event_end, + details.previous_event_start, details.previous_event_end, details.previous_system_id, + ) + else + dispatch_event_change( + details.event_id, details.system_id, details.event_ical_uid, + host, details.title, event_start, event_end, + details.previous_event_start, details.previous_event_end, details.previous_system_id, + ) + end + rescue error + logger.error { error.inspect_with_backtrace } + self[:error_count] = @error_count += 1 + self[:last_error] = { + error: error.message, + time: Time.local.to_s, + user: payload, + } + end + + # Buffers a change so the burst of signals for one edit collapses into a single + # email: keeps the earliest previous_*, advances to the latest current values. + private def enqueue_event_change( + event_id : String, + system_id : String, + event_ical_uid : String?, + host : String, + title : String?, + current_start : Int64, + current_end : Int64, + previous_start : Int64?, + previous_end : Int64?, + previous_system_id : String?, + ) + schedule_flush = false + @pending_event_changes_lock.synchronize do + if pending = @pending_event_changes[event_id]? + pending.system_id = system_id + pending.event_ical_uid = event_ical_uid + pending.host = host + pending.title = title + pending.current_start = current_start + pending.current_end = current_end + else + @pending_event_changes[event_id] = PendingEventChange.new( + event_id, system_id, event_ical_uid, host, title, + current_start, current_end, previous_start, previous_end, previous_system_id, + ) + schedule_flush = true + end + end + + # Schedule outside the lock; the window runs from the first signal in the burst. + schedule.in(@event_change_debounce.seconds) { flush_event_change(event_id) } if schedule_flush + end + + private def flush_event_change(event_id : String) + pending = @pending_event_changes_lock.synchronize { @pending_event_changes.delete(event_id) } + return unless pending + + dispatch_event_change( + pending.event_id, pending.system_id, pending.event_ical_uid, + pending.host, pending.title, pending.current_start, pending.current_end, + pending.previous_start, pending.previous_end, pending.previous_system_id, + ) + rescue error + logger.error { error.inspect_with_backtrace } + self[:error_count] = @error_count += 1 + self[:last_error] = { + error: error.message, + time: Time.local.to_s, + user: "flush_event_change #{event_id}", + } + end + + # Resolves locations, fetches guests and emails visitors about a change. + # Shared by the immediate and debounced paths. + private def dispatch_event_change( + event_id : String, + system_id : String, + event_ical_uid : String?, + host : String, + title : String?, + current_start : Int64, + current_end : Int64, + previous_start : Int64?, + previous_end : Int64?, + previous_system_id : String?, + ) + # Skip a coalesced no-op (e.g. an A->B->A flip-flop that nets to no change). + changed = false + changed = true if previous_start && previous_start != current_start + changed = true if previous_end && previous_end != current_end + changed = true if previous_system_id && previous_system_id != system_id + return unless changed + current_building_name = building_zone.display_name.presence || building_zone.name current_room_name = @booking_space_name - current_room_name, current_building_name = resolve_system_location_names(details.system_id, current_room_name, current_building_name) + current_room_name, current_building_name = resolve_system_location_names(system_id, current_room_name, current_building_name) # Default the previous location to the current one; only override it when the # room actually changed. This keeps date/time-only edits showing the same @@ -773,33 +904,25 @@ class Place::VisitorMailer < PlaceOS::Driver previous_building_name = current_building_name previous_room_name = current_room_name - if (prev_sys_id = details.previous_system_id) && prev_sys_id != details.system_id + if (prev_sys_id = previous_system_id) && prev_sys_id != system_id # Use "unknown" as the room fallback so a failed lookup surfaces in the # email rather than silently showing the current room name. previous_room_name, previous_building_name = resolve_system_location_names(prev_sys_id, "unknown", current_building_name) end - guests = staff_api.event_guests(details.event_id, details.system_id, details.event_ical_uid).get.as_a + guests = staff_api.event_guests(event_id, system_id, event_ical_uid).get.as_a send_booking_changed_emails( guests, @event_changed_template, host, - event_start, - details.title, - details.previous_event_start, + current_start, + title, + previous_start, previous_building_name, previous_room_name, current_building_name, current_room_name, ) - rescue error - logger.error { error.inspect_with_backtrace } - self[:error_count] = @error_count += 1 - self[:last_error] = { - error: error.message, - time: Time.local.to_s, - user: payload, - } end # `building_name` / `room_name` override the current location names; when @@ -1059,6 +1182,34 @@ class Place::VisitorMailer < PlaceOS::Driver property parent_id : String? end + # A staff/event/changed change buffered awaiting a debounced flush. + class PendingEventChange + property event_id : String + property system_id : String + property event_ical_uid : String? + property host : String + property title : String? + property current_start : Int64 + property current_end : Int64 + property previous_start : Int64? + property previous_end : Int64? + property previous_system_id : String? + + def initialize( + @event_id, + @system_id, + @event_ical_uid, + @host, + @title, + @current_start, + @current_end, + @previous_start, + @previous_end, + @previous_system_id, + ) + end + end + # zone_id, timeout, zone alias ZoneCache = Hash(String, Tuple(Int64, ZoneDetails)) diff --git a/drivers/place/visitor_mailer_spec.cr b/drivers/place/visitor_mailer_spec.cr index 37bd18fe35..4170933ee1 100644 --- a/drivers/place/visitor_mailer_spec.cr +++ b/drivers/place/visitor_mailer_spec.cr @@ -1713,4 +1713,93 @@ DriverSpecs.mock_driver "Place::VisitorMailer" do system(:Mailer)[:last_to].should eq "old-host-n@example.com" system(:Mailer)[:last_template].should eq ["visitor_invited", "notify_original_host"] system(:Mailer)[:last_args]["event_date"].raw.should be_nil + + # ================================================================== + # event_change_debounce — coalesce the Office365 signal burst (PPT-2375) + # ================================================================== + # + # One edit arrives as an A -> B -> A flip-flop (Wed->Thu, Thu->Wed, Wed->Thu) + # of staff/event/changed signals; the debounce must collapse it into ONE email + # showing the true net change. + + settings({ + timezone: "GMT", + booking_space_name: "Client Floor", + invite_zone_tag: "building", + event_change_debounce: 3, + }) + sleep 1.0 + + gmt = Time::Location.load("GMT") + wed_start = now + 100_000 + thu_start = wed_start + 86_400 # exactly one day later + + # Wed -> Thu (organizer copy) + debounce_signal_a1 = { + action: "update", + system_id: "sys-room1", + event_id: "evt-debounce", + event_ical_uid: "ical-debounce", + host: "host@example.com", + resource: "room1@example.com", + title: "Temporal Uncertainty Forecasts", + event_start: thu_start, + event_end: thu_start + 1800, + zones: ["zone-building", "zone-room"], + previous_event_start: wed_start, + previous_event_end: wed_start + 1800, + }.to_json + + # Thu -> Wed (stale room-mailbox echo — the reversed signal) + debounce_signal_b = { + action: "update", + system_id: "sys-room1", + event_id: "evt-debounce", + event_ical_uid: "ical-debounce", + host: "host@example.com", + resource: "room1@example.com", + title: "Temporal Uncertainty Forecasts", + event_start: wed_start, + event_end: wed_start + 1800, + zones: ["zone-building", "zone-room"], + previous_event_start: thu_start, + previous_event_end: thu_start + 1800, + }.to_json + + # Wed -> Thu (room copy catches up — settled state) + debounce_signal_a2 = { + action: "update", + system_id: "sys-room1", + event_id: "evt-debounce", + event_ical_uid: "ical-debounce", + host: "host@example.com", + resource: "room1@example.com", + title: "Temporal Uncertainty Forecasts", + event_start: thu_start, + event_end: thu_start + 1800, + zones: ["zone-building", "zone-room"], + previous_event_start: wed_start, + previous_event_end: wed_start + 1800, + }.to_json + + count_before_debounce = system(:Mailer)[:send_count].as_i + + publish("staff/event/changed", debounce_signal_a1) + publish("staff/event/changed", debounce_signal_b) + publish("staff/event/changed", debounce_signal_a2) + + # Still inside the 3s window: nothing should have been sent yet. + sleep 1.0 + system(:Mailer)[:send_count].should eq count_before_debounce + + # After the window closes the burst collapses into a single email. + sleep 3.0 + system(:Mailer)[:send_count].should eq count_before_debounce + 1 + system(:Mailer)[:last_to].should eq "visitor@external.com" + system(:Mailer)[:last_template].should eq ["visitor_invited", "event_changed"] + + # The one email must show the true net change (Wed -> Thu), not the reversed echo. + debounce_args = system(:Mailer)[:last_args] + debounce_args["event_date"].should eq Time.unix(thu_start).in(gmt).to_s("%A, %-d %B") + debounce_args["previous_event_date"].should eq Time.unix(wed_start).in(gmt).to_s("%A, %-d %B") end From ccc14237f96253b743dc53b4200384f65c196709 Mon Sep 17 00:00:00 2001 From: Mia Bennett Date: Thu, 23 Jul 2026 15:33:34 +0930 Subject: [PATCH 2/7] fix(visitor_mailer): enable event change debounce by default 15s (PPT-2375) --- drivers/place/visitor_mailer.cr | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/drivers/place/visitor_mailer.cr b/drivers/place/visitor_mailer.cr index b665087521..9a5f3431af 100644 --- a/drivers/place/visitor_mailer.cr +++ b/drivers/place/visitor_mailer.cr @@ -42,8 +42,8 @@ class Place::VisitorMailer < PlaceOS::Driver # Office365 emits several staff/event/changed signals per edit (organizer + # room mailbox copies, propagation lag), causing duplicate/contradictory - # visitor emails (PPT-2375). Coalesce them over this many seconds; 0 disables. - event_change_debounce: 0, + # visitor emails (PPT-2375). Coalesce over this many seconds; on by default, 0 disables. + event_change_debounce: 15, disable_qr_code: false, send_network_credentials: false, network_password_length: DEFAULT_PASSWORD_LENGTH, @@ -164,7 +164,7 @@ class Place::VisitorMailer < PlaceOS::Driver # Coalescing buffer for staff/event/changed; only holds events currently # within their debounce window. - @event_change_debounce : Int32 = 0 + @event_change_debounce : Int32 = 15 @pending_event_changes : Hash(String, PendingEventChange) = {} of String => PendingEventChange @pending_event_changes_lock : Mutex = Mutex.new @@ -187,7 +187,7 @@ class Place::VisitorMailer < PlaceOS::Driver @booking_changed_template = setting?(String, :booking_changed_template) || "booking_changed" @event_changed_template = setting?(String, :event_changed_template) || "event_changed" @group_event_template = setting?(String, :group_event_template) || "group_event" - @event_change_debounce = setting?(Int32, :event_change_debounce) || 0 + @event_change_debounce = setting?(Int32, :event_change_debounce) || 15 @disable_qr_code = setting?(Bool, :disable_qr_code) || false @determine_host_name_using = setting?(String, :determine_host_name_using) || "calendar-driver" @send_network_credentials = setting?(Bool, :send_network_credentials) || false From 8447509ba1f51e867c9b4db1a811404b023b7f91 Mon Sep 17 00:00:00 2001 From: Mia Bennett Date: Thu, 23 Jul 2026 15:38:51 +0930 Subject: [PATCH 3/7] docs(visitor_mailer): shorten client-facing debounce setting comment --- drivers/place/visitor_mailer.cr | 4 +--- 1 file changed, 1 insertion(+), 3 deletions(-) diff --git a/drivers/place/visitor_mailer.cr b/drivers/place/visitor_mailer.cr index 9a5f3431af..2f9708e527 100644 --- a/drivers/place/visitor_mailer.cr +++ b/drivers/place/visitor_mailer.cr @@ -40,9 +40,7 @@ class Place::VisitorMailer < PlaceOS::Driver event_changed_template: "event_changed", group_event_template: "group_event", - # Office365 emits several staff/event/changed signals per edit (organizer + - # room mailbox copies, propagation lag), causing duplicate/contradictory - # visitor emails (PPT-2375). Coalesce over this many seconds; on by default, 0 disables. + # Combine duplicate change emails sent within this many seconds; 0 disables. event_change_debounce: 15, disable_qr_code: false, send_network_credentials: false, From 211156b3f555030f28fc55696c1c80c00c4308a8 Mon Sep 17 00:00:00 2001 From: Mia Bennett Date: Mon, 27 Jul 2026 15:29:25 +0930 Subject: [PATCH 4/7] fix(visitor_mailer): drain debounced event changes on unload (PPT-2375) The scheduler is terminated before on_unload runs, so any change still inside its debounce window was silently dropped on restart. Extract the settings-update drain into a shared helper and call it from on_unload with a 5s bound, staying inside the driver manager's 6s budget. Also document the pending change buffer key/value and the fields of PendingEventChange. --- drivers/place/visitor_mailer.cr | 83 +++++++++++++++++++++----- drivers/place/visitor_mailer_readme.md | 20 +++++++ drivers/place/visitor_mailer_spec.cr | 56 +++++++++++++++++ 3 files changed, 143 insertions(+), 16 deletions(-) diff --git a/drivers/place/visitor_mailer.cr b/drivers/place/visitor_mailer.cr index 2f9708e527..f3ce44742a 100644 --- a/drivers/place/visitor_mailer.cr +++ b/drivers/place/visitor_mailer.cr @@ -162,8 +162,11 @@ class Place::VisitorMailer < PlaceOS::Driver # Coalescing buffer for staff/event/changed; only holds events currently # within their debounce window. + # seconds to buffer a change before emailing; 0 dispatches immediately @event_change_debounce : Int32 = 15 + # event_id => coalesced change awaiting its flush @pending_event_changes : Hash(String, PendingEventChange) = {} of String => PendingEventChange + # guards the buffer: mutated from monitor callbacks, schedule and drain fibers @pending_event_changes_lock : Mutex = Mutex.new @uri : URI = URI.new @@ -218,22 +221,7 @@ class Place::VisitorMailer < PlaceOS::Driver zones = control_system_zone_list # Flush in-flight debounced changes before schedule.clear cancels their timers. - draining = @pending_event_changes_lock.synchronize do - values = @pending_event_changes.values - @pending_event_changes.clear - values - end - draining.each do |pending| - spawn do - dispatch_event_change( - pending.event_id, pending.system_id, pending.event_ical_uid, - pending.host, pending.title, pending.current_start, pending.current_end, - pending.previous_start, pending.previous_end, pending.previous_system_id, - ) - rescue error - logger.warn(exception: error) { "failed to flush pending event change on settings update" } - end - end + drain_pending_event_changes("settings update") schedule.clear if reminders = @send_reminders @@ -242,6 +230,13 @@ class Place::VisitorMailer < PlaceOS::Driver spawn { ensure_building_zone(zones) } end + # The scheduler is terminated before this runs, so any change still inside its + # debounce window would never be emailed. Drain it, bounded so we return within + # the driver manager's on_unload budget. + def on_unload + drain_pending_event_changes("driver unloading", wait: 5.seconds) + end + def control_system_zone_list config.control_system.not_nil!.zones # ameba:disable Lint/NotNil end @@ -858,6 +853,54 @@ class Place::VisitorMailer < PlaceOS::Driver schedule.in(@event_change_debounce.seconds) { flush_event_change(event_id) } if schedule_flush end + # Dispatches every buffered change immediately, emptying the buffer. + # Used by the lifecycle hooks, where the scheduled flush timers are about to + # be cancelled and the buffered notifications would otherwise be lost. + # `wait` bounds how long we block for the sends to complete (the driver + # manager tears the module down ~6s into on_unload); nil returns immediately. + private def drain_pending_event_changes(reason : String, wait : Time::Span? = nil) : Nil + draining = @pending_event_changes_lock.synchronize do + values = @pending_event_changes.values + @pending_event_changes.clear + values + end + return if draining.empty? + + logger.debug { "flushing #{draining.size} pending event change(s): #{reason}" } + + complete = Channel(Nil).new(draining.size) + draining.each do |pending| + spawn do + dispatch_event_change( + pending.event_id, pending.system_id, pending.event_ical_uid, + pending.host, pending.title, pending.current_start, pending.current_end, + pending.previous_start, pending.previous_end, pending.previous_system_id, + ) + rescue error + logger.warn(exception: error) { "failed to flush pending event change #{pending.event_id}: #{reason}" } + ensure + complete.send(nil) + end + end + return unless wait + + deadline = Time.monotonic + wait + draining.size.times do |index| + remaining = deadline - Time.monotonic + if remaining <= Time::Span.zero + logger.warn { "timeout flushing pending event changes: #{reason}, #{draining.size - index} of #{draining.size} still in flight" } + break + end + + select + when complete.receive + when timeout(remaining) + logger.warn { "timeout flushing pending event changes: #{reason}, #{draining.size - index} of #{draining.size} still in flight" } + break + end + end + end + private def flush_event_change(event_id : String) pending = @pending_event_changes_lock.synchronize { @pending_event_changes.delete(event_id) } return unless pending @@ -1188,16 +1231,24 @@ class Place::VisitorMailer < PlaceOS::Driver end # A staff/event/changed change buffered awaiting a debounced flush. + # `current_*` track the latest values seen in the burst, `previous_*` are kept + # from the first signal so the email describes the net change of the edit. class PendingEventChange + # the calendar event being edited, also the buffer key property event_id : String + # the room the event currently sits in (latest signal) property system_id : String property event_ical_uid : String? + # the current host, required to render and reply-to the email property host : String property title : String? + # latest event timing seen in the burst property current_start : Int64 property current_end : Int64 + # event timing before the edit, from the first signal in the burst property previous_start : Int64? property previous_end : Int64? + # the room before the edit, from the first signal in the burst property previous_system_id : String? def initialize( diff --git a/drivers/place/visitor_mailer_readme.md b/drivers/place/visitor_mailer_readme.md index 7702e3511c..a6ccca2e45 100644 --- a/drivers/place/visitor_mailer_readme.md +++ b/drivers/place/visitor_mailer_readme.md @@ -26,6 +26,26 @@ Requires the following drivers in the system: skip_host_email: true ``` +## Debouncing event changes + +A single calendar edit is rarely a single signal: Office365 emits a burst of +`staff/event/changed` updates (the organizer copy, then each room mailbox catching +up), which can briefly flip-flop between the old and new values. Sending an email +per signal spams visitors with contradictory notifications. + +`event_change_debounce` (seconds, default `15`) buffers the burst for one event and +sends a single email describing the net change once the window closes. Set it to `0` +to email on every signal. + +```yaml + # Combine duplicate change emails sent within this many seconds; 0 disables. + event_change_debounce: 15 +``` + +Buffered changes are drained (emailed immediately) when the module's settings are +updated and when the driver is unloaded, so a restart or a settings change does not +silently drop a pending notification. + ## Reply-To Visitor emails set a `Reply-To` header so replies reach a useful person rather than diff --git a/drivers/place/visitor_mailer_spec.cr b/drivers/place/visitor_mailer_spec.cr index 0fb1c7725d..87332a1fe1 100644 --- a/drivers/place/visitor_mailer_spec.cr +++ b/drivers/place/visitor_mailer_spec.cr @@ -1815,6 +1815,62 @@ DriverSpecs.mock_driver "Place::VisitorMailer" do debounce_args["event_date"].should eq Time.unix(thu_start).in(gmt).to_s("%A, %-d %B") debounce_args["previous_event_date"].should eq Time.unix(wed_start).in(gmt).to_s("%A, %-d %B") + # ------------------------------------------------------------------ + # Test 38b: a buffered change is drained by the lifecycle hooks rather + # than dropped. The scheduled flush timers are cancelled on a + # settings update (and terminated on unload), so the buffer is + # drained first — this covers the same drain the driver runs + # from on_unload, which the spec harness cannot invoke. + # ------------------------------------------------------------------ + + settings({ + timezone: "GMT", + booking_space_name: "Client Floor", + invite_zone_tag: "building", + event_change_debounce: 30, + }) + sleep 1.0 + + drain_signal = { + action: "update", + system_id: "sys-room1", + event_id: "evt-drain", + event_ical_uid: "ical-drain", + host: "host@example.com", + resource: "room1@example.com", + title: "Unload Drain", + event_start: thu_start, + event_end: thu_start + 1800, + zones: ["zone-building", "zone-room"], + previous_event_start: wed_start, + previous_event_end: wed_start + 1800, + }.to_json + + count_before_drain = system(:Mailer)[:send_count].as_i + + publish("staff/event/changed", drain_signal) + + # Well inside the 30s window: the change is buffered, nothing sent yet. + sleep 1.0 + system(:Mailer)[:send_count].should eq count_before_drain + + # The lifecycle hook drains the buffer before the flush timer is discarded. + settings({ + timezone: "GMT", + booking_space_name: "Client Floor", + invite_zone_tag: "building", + event_change_debounce: 0, + }) + sleep 1.5 + + system(:Mailer)[:send_count].should eq count_before_drain + 1 + system(:Mailer)[:last_to].should eq "visitor@external.com" + system(:Mailer)[:last_template].should eq ["visitor_invited", "event_changed"] + + drain_args = system(:Mailer)[:last_args] + drain_args["event_date"].should eq Time.unix(thu_start).in(gmt).to_s("%A, %-d %B") + drain_args["previous_event_date"].should eq Time.unix(wed_start).in(gmt).to_s("%A, %-d %B") + # ================================================================== # visitor check-in tests (PPT-2535) # ================================================================== From 7a8a3f10ccdd7f2b3e12a2bd25e2c74287abf9b5 Mon Sep 17 00:00:00 2001 From: Mia Bennett Date: Mon, 27 Jul 2026 16:13:33 +0930 Subject: [PATCH 5/7] refactor(visitor_mailer): sweep debounced event changes on a timer (PPT-2375) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Replace the timer per buffered event with a single periodic sweep. Each change records when its burst started and the sweep sends anything that has aged past the debounce, so buffering no longer has to schedule a flush outside the lock or track whether one is already pending. The buffer now survives a settings update — the fresh sweep picks the entries up, so an unrelated settings change no longer cuts the window short. Only disabling the debounce flushes, since no sweep would run. Also pass the buffered change around as an object rather than threading ten positional arguments through every call site. --- drivers/place/visitor_mailer.cr | 191 +++++++++++-------------- drivers/place/visitor_mailer_readme.md | 7 +- drivers/place/visitor_mailer_spec.cr | 64 +++++++-- 3 files changed, 142 insertions(+), 120 deletions(-) diff --git a/drivers/place/visitor_mailer.cr b/drivers/place/visitor_mailer.cr index f3ce44742a..d2cfa4559f 100644 --- a/drivers/place/visitor_mailer.cr +++ b/drivers/place/visitor_mailer.cr @@ -220,21 +220,28 @@ class Place::VisitorMailer < PlaceOS::Driver zones = control_system_zone_list - # Flush in-flight debounced changes before schedule.clear cancels their timers. - drain_pending_event_changes("settings update") + # The sweep below picks up anything still buffered; only when the debounce has + # been turned off is there nothing left to flush it. + flush_event_changes("debounce disabled") if @event_change_debounce <= 0 schedule.clear if reminders = @send_reminders schedule.cron(reminders, @time_zone) { send_reminder_emails } end + + # Sweep often enough to keep short debounce windows accurate, but no more than + # every 5s for long ones — the effective window is the configured debounce plus + # up to one sweep interval. + schedule.every(@event_change_debounce.clamp(1, 5).seconds) { sweep_event_changes } if @event_change_debounce > 0 + spawn { ensure_building_zone(zones) } end - # The scheduler is terminated before this runs, so any change still inside its - # debounce window would never be emailed. Drain it, bounded so we return within - # the driver manager's on_unload budget. + # The scheduler is terminated before this runs, so a change still inside its + # debounce window would never be swept. Flush the buffer, bounded so we return + # within the driver manager's on_unload budget. def on_unload - drain_pending_event_changes("driver unloading", wait: 5.seconds) + flush_event_changes("driver unloading", wait: 5.seconds) end def control_system_zone_list @@ -794,19 +801,12 @@ class Place::VisitorMailer < PlaceOS::Driver return unless fields_changed # Coalesce the burst of signals Office365 emits per edit into one email. - if @event_change_debounce > 0 - enqueue_event_change( - details.event_id, details.system_id, details.event_ical_uid, - host, details.title, event_start, event_end, - details.previous_event_start, details.previous_event_end, details.previous_system_id, - ) - else - dispatch_event_change( - details.event_id, details.system_id, details.event_ical_uid, - host, details.title, event_start, event_end, - details.previous_event_start, details.previous_event_end, details.previous_system_id, - ) - end + change = PendingEventChange.new( + details.event_id, details.system_id, details.event_ical_uid, + host, details.title, event_start, event_end, + details.previous_event_start, details.previous_event_end, details.previous_system_id, + ) + @event_change_debounce > 0 ? buffer_event_change(change) : dispatch_event_change(change) rescue error logger.error { error.inspect_with_backtrace } self[:error_count] = @error_count += 1 @@ -818,66 +818,55 @@ class Place::VisitorMailer < PlaceOS::Driver end # Buffers a change so the burst of signals for one edit collapses into a single - # email: keeps the earliest previous_*, advances to the latest current values. - private def enqueue_event_change( - event_id : String, - system_id : String, - event_ical_uid : String?, - host : String, - title : String?, - current_start : Int64, - current_end : Int64, - previous_start : Int64?, - previous_end : Int64?, - previous_system_id : String?, - ) - schedule_flush = false + # email. The periodic sweep sends it once the debounce window has elapsed. + private def buffer_event_change(change : PendingEventChange) : Nil @pending_event_changes_lock.synchronize do - if pending = @pending_event_changes[event_id]? - pending.system_id = system_id - pending.event_ical_uid = event_ical_uid - pending.host = host - pending.title = title - pending.current_start = current_start - pending.current_end = current_end + if pending = @pending_event_changes[change.event_id]? + pending.merge(change) else - @pending_event_changes[event_id] = PendingEventChange.new( - event_id, system_id, event_ical_uid, host, title, - current_start, current_end, previous_start, previous_end, previous_system_id, - ) - schedule_flush = true + @pending_event_changes[change.event_id] = change end end + end - # Schedule outside the lock; the window runs from the first signal in the burst. - schedule.in(@event_change_debounce.seconds) { flush_event_change(event_id) } if schedule_flush + # Sends any change that has been buffered for the full debounce window. + # A single sweep replaces a timer per event. + private def sweep_event_changes : Nil + flush_event_changes("debounce window elapsed", older_than: Time.monotonic - @event_change_debounce.seconds) end - # Dispatches every buffered change immediately, emptying the buffer. - # Used by the lifecycle hooks, where the scheduled flush timers are about to - # be cancelled and the buffered notifications would otherwise be lost. + # Removes the matching buffered changes and dispatches each in its own fiber — + # a slow send must not stall the sweep or the shutdown drain. + # `older_than` limits the flush to entries buffered before that point (the + # sweep); nil flushes the whole buffer (the lifecycle drain). # `wait` bounds how long we block for the sends to complete (the driver # manager tears the module down ~6s into on_unload); nil returns immediately. - private def drain_pending_event_changes(reason : String, wait : Time::Span? = nil) : Nil - draining = @pending_event_changes_lock.synchronize do - values = @pending_event_changes.values - @pending_event_changes.clear - values + private def flush_event_changes(reason : String, older_than : Time::Span? = nil, wait : Time::Span? = nil) : Nil + flushing = @pending_event_changes_lock.synchronize do + ready = if cutoff = older_than + @pending_event_changes.values.select { |pending| pending.first_seen <= cutoff } + else + @pending_event_changes.values + end + ready.each { |pending| @pending_event_changes.delete(pending.event_id) } + ready end - return if draining.empty? + return if flushing.empty? - logger.debug { "flushing #{draining.size} pending event change(s): #{reason}" } + logger.debug { "flushing #{flushing.size} pending event change(s): #{reason}" } - complete = Channel(Nil).new(draining.size) - draining.each do |pending| + complete = Channel(Nil).new(flushing.size) + flushing.each do |pending| spawn do - dispatch_event_change( - pending.event_id, pending.system_id, pending.event_ical_uid, - pending.host, pending.title, pending.current_start, pending.current_end, - pending.previous_start, pending.previous_end, pending.previous_system_id, - ) + dispatch_event_change(pending) rescue error - logger.warn(exception: error) { "failed to flush pending event change #{pending.event_id}: #{reason}" } + logger.error { error.inspect_with_backtrace } + self[:error_count] = @error_count += 1 + self[:last_error] = { + error: error.message, + time: Time.local.to_s, + user: "flushing event change #{pending.event_id}: #{reason}", + } ensure complete.send(nil) end @@ -885,59 +874,29 @@ class Place::VisitorMailer < PlaceOS::Driver return unless wait deadline = Time.monotonic + wait - draining.size.times do |index| + flushing.size.times do |index| remaining = deadline - Time.monotonic - if remaining <= Time::Span.zero - logger.warn { "timeout flushing pending event changes: #{reason}, #{draining.size - index} of #{draining.size} still in flight" } - break - end + remaining = Time::Span.zero if remaining < Time::Span.zero select when complete.receive when timeout(remaining) - logger.warn { "timeout flushing pending event changes: #{reason}, #{draining.size - index} of #{draining.size} still in flight" } + logger.warn { "timeout flushing pending event changes: #{reason}, #{flushing.size - index} of #{flushing.size} still in flight" } break end end end - private def flush_event_change(event_id : String) - pending = @pending_event_changes_lock.synchronize { @pending_event_changes.delete(event_id) } - return unless pending - - dispatch_event_change( - pending.event_id, pending.system_id, pending.event_ical_uid, - pending.host, pending.title, pending.current_start, pending.current_end, - pending.previous_start, pending.previous_end, pending.previous_system_id, - ) - rescue error - logger.error { error.inspect_with_backtrace } - self[:error_count] = @error_count += 1 - self[:last_error] = { - error: error.message, - time: Time.local.to_s, - user: "flush_event_change #{event_id}", - } - end - # Resolves locations, fetches guests and emails visitors about a change. # Shared by the immediate and debounced paths. - private def dispatch_event_change( - event_id : String, - system_id : String, - event_ical_uid : String?, - host : String, - title : String?, - current_start : Int64, - current_end : Int64, - previous_start : Int64?, - previous_end : Int64?, - previous_system_id : String?, - ) + private def dispatch_event_change(change : PendingEventChange) + system_id = change.system_id + previous_system_id = change.previous_system_id + # Skip a coalesced no-op (e.g. an A->B->A flip-flop that nets to no change). changed = false - changed = true if previous_start && previous_start != current_start - changed = true if previous_end && previous_end != current_end + changed = true if (previous_start = change.previous_start) && previous_start != change.current_start + changed = true if (previous_end = change.previous_end) && previous_end != change.current_end changed = true if previous_system_id && previous_system_id != system_id return unless changed @@ -958,14 +917,14 @@ class Place::VisitorMailer < PlaceOS::Driver previous_room_name, previous_building_name = resolve_system_location_names(prev_sys_id, "unknown", current_building_name) end - guests = staff_api.event_guests(event_id, system_id, event_ical_uid).get.as_a + guests = staff_api.event_guests(change.event_id, system_id, change.event_ical_uid).get.as_a send_booking_changed_emails( guests, @event_changed_template, - host, - current_start, - title, - previous_start, + change.host, + change.current_start, + change.title, + change.previous_start, previous_building_name, previous_room_name, current_building_name, @@ -1250,6 +1209,8 @@ class Place::VisitorMailer < PlaceOS::Driver property previous_end : Int64? # the room before the edit, from the first signal in the burst property previous_system_id : String? + # when the burst started; the debounce window is measured from here + getter first_seen : Time::Span = Time.monotonic def initialize( @event_id, @@ -1264,6 +1225,18 @@ class Place::VisitorMailer < PlaceOS::Driver @previous_system_id, ) end + + # Advance to the latest values seen in the burst. `first_seen` and the + # `previous_*` values stay as they were when the burst started, so the email + # always describes the net change of the whole edit. + def merge(change : PendingEventChange) : Nil + @system_id = change.system_id + @event_ical_uid = change.event_ical_uid + @host = change.host + @title = change.title + @current_start = change.current_start + @current_end = change.current_end + end end # zone_id, timeout, zone diff --git a/drivers/place/visitor_mailer_readme.md b/drivers/place/visitor_mailer_readme.md index a6ccca2e45..2404426885 100644 --- a/drivers/place/visitor_mailer_readme.md +++ b/drivers/place/visitor_mailer_readme.md @@ -42,9 +42,10 @@ to email on every signal. event_change_debounce: 15 ``` -Buffered changes are drained (emailed immediately) when the module's settings are -updated and when the driver is unloaded, so a restart or a settings change does not -silently drop a pending notification. +Buffered changes are swept on a timer rather than each having its own, so the actual +delay is the configured debounce plus up to one sweep interval (at most 5s). Anything +still buffered is emailed immediately when the driver is unloaded, or when the +debounce is turned off, so a restart never silently drops a pending notification. ## Reply-To diff --git a/drivers/place/visitor_mailer_spec.cr b/drivers/place/visitor_mailer_spec.cr index 87332a1fe1..7861f49596 100644 --- a/drivers/place/visitor_mailer_spec.cr +++ b/drivers/place/visitor_mailer_spec.cr @@ -1804,8 +1804,9 @@ DriverSpecs.mock_driver "Place::VisitorMailer" do sleep 1.0 system(:Mailer)[:send_count].should eq count_before_debounce - # After the window closes the burst collapses into a single email. - sleep 3.0 + # After the window closes the burst collapses into a single email. The sweep + # runs on an interval, so allow the debounce plus one sweep interval. + sleep 6.0 system(:Mailer)[:send_count].should eq count_before_debounce + 1 system(:Mailer)[:last_to].should eq "visitor@external.com" system(:Mailer)[:last_template].should eq ["visitor_invited", "event_changed"] @@ -1816,11 +1817,58 @@ DriverSpecs.mock_driver "Place::VisitorMailer" do debounce_args["previous_event_date"].should eq Time.unix(wed_start).in(gmt).to_s("%A, %-d %B") # ------------------------------------------------------------------ - # Test 38b: a buffered change is drained by the lifecycle hooks rather - # than dropped. The scheduled flush timers are cancelled on a - # settings update (and terminated on unload), so the buffer is - # drained first — this covers the same drain the driver runs - # from on_unload, which the spec harness cannot invoke. + # Test 38b: a change buffered when the settings are updated keeps its + # window and is still swept out afterwards, rather than being + # dropped or emailed early. + # ------------------------------------------------------------------ + + survives_signal = { + action: "update", + system_id: "sys-room1", + event_id: "evt-survives-update", + event_ical_uid: "ical-survives-update", + host: "host@example.com", + resource: "room1@example.com", + title: "Settings Update", + event_start: thu_start, + event_end: thu_start + 1800, + zones: ["zone-building", "zone-room"], + previous_event_start: wed_start, + previous_event_end: wed_start + 1800, + }.to_json + + count_before_survives = system(:Mailer)[:send_count].as_i + + publish("staff/event/changed", survives_signal) + sleep 1.0 + system(:Mailer)[:send_count].should eq count_before_survives + + # Settings update mid-window: the buffer survives and the new sweep picks it up. + settings({ + timezone: "GMT", + booking_space_name: "Client Floor", + invite_zone_tag: "building", + event_change_debounce: 3, + }) + + # The update must not cut the window short either. + sleep 0.5 + system(:Mailer)[:send_count].should eq count_before_survives + + sleep 6.0 + system(:Mailer)[:send_count].should eq count_before_survives + 1 + system(:Mailer)[:last_to].should eq "visitor@external.com" + system(:Mailer)[:last_template].should eq ["visitor_invited", "event_changed"] + + survives_args = system(:Mailer)[:last_args] + survives_args["event_date"].should eq Time.unix(thu_start).in(gmt).to_s("%A, %-d %B") + survives_args["previous_event_date"].should eq Time.unix(wed_start).in(gmt).to_s("%A, %-d %B") + + # ------------------------------------------------------------------ + # Test 38c: turning the debounce off flushes whatever is buffered — + # no sweep will run to pick it up. This is the same flush the + # driver runs from on_unload, which the spec harness cannot + # invoke directly. # ------------------------------------------------------------------ settings({ @@ -1854,7 +1902,7 @@ DriverSpecs.mock_driver "Place::VisitorMailer" do sleep 1.0 system(:Mailer)[:send_count].should eq count_before_drain - # The lifecycle hook drains the buffer before the flush timer is discarded. + # Disabling the debounce flushes the buffer instead of orphaning it. settings({ timezone: "GMT", booking_space_name: "Client Floor", From 1656741e567619cbec3c92edde21c33f473aba79 Mon Sep 17 00:00:00 2001 From: Mia Bennett Date: Mon, 27 Jul 2026 16:22:44 +0930 Subject: [PATCH 6/7] docs(visitor_mailer): trim the event change debounce comments --- drivers/place/visitor_mailer.cr | 55 +++++++++------------------- drivers/place/visitor_mailer_spec.cr | 19 ++++------ 2 files changed, 26 insertions(+), 48 deletions(-) diff --git a/drivers/place/visitor_mailer.cr b/drivers/place/visitor_mailer.cr index d2cfa4559f..50102e8b0d 100644 --- a/drivers/place/visitor_mailer.cr +++ b/drivers/place/visitor_mailer.cr @@ -160,13 +160,11 @@ class Place::VisitorMailer < PlaceOS::Driver @skip_event_linked_booking_email : Bool = true @skip_host_email : Bool = true - # Coalescing buffer for staff/event/changed; only holds events currently - # within their debounce window. - # seconds to buffer a change before emailing; 0 dispatches immediately + # Coalescing buffer for staff/event/changed, swept once the window elapses. + # seconds to buffer a change; 0 emails on every signal @event_change_debounce : Int32 = 15 # event_id => coalesced change awaiting its flush @pending_event_changes : Hash(String, PendingEventChange) = {} of String => PendingEventChange - # guards the buffer: mutated from monitor callbacks, schedule and drain fibers @pending_event_changes_lock : Mutex = Mutex.new @uri : URI = URI.new @@ -220,8 +218,7 @@ class Place::VisitorMailer < PlaceOS::Driver zones = control_system_zone_list - # The sweep below picks up anything still buffered; only when the debounce has - # been turned off is there nothing left to flush it. + # The sweep below picks up the rest; with the debounce off nothing would. flush_event_changes("debounce disabled") if @event_change_debounce <= 0 schedule.clear @@ -229,17 +226,14 @@ class Place::VisitorMailer < PlaceOS::Driver schedule.cron(reminders, @time_zone) { send_reminder_emails } end - # Sweep often enough to keep short debounce windows accurate, but no more than - # every 5s for long ones — the effective window is the configured debounce plus - # up to one sweep interval. + # Sweeps at most every 5s, so a change waits its debounce plus up to one interval. schedule.every(@event_change_debounce.clamp(1, 5).seconds) { sweep_event_changes } if @event_change_debounce > 0 spawn { ensure_building_zone(zones) } end - # The scheduler is terminated before this runs, so a change still inside its - # debounce window would never be swept. Flush the buffer, bounded so we return - # within the driver manager's on_unload budget. + # The scheduler is dead by now, so nothing else would sweep the buffer. + # Bounded to return within the driver manager's 6s unload budget. def on_unload flush_event_changes("driver unloading", wait: 5.seconds) end @@ -817,8 +811,7 @@ class Place::VisitorMailer < PlaceOS::Driver } end - # Buffers a change so the burst of signals for one edit collapses into a single - # email. The periodic sweep sends it once the debounce window has elapsed. + # Collapses the burst of signals for one edit into a single buffered change. private def buffer_event_change(change : PendingEventChange) : Nil @pending_event_changes_lock.synchronize do if pending = @pending_event_changes[change.event_id]? @@ -829,18 +822,14 @@ class Place::VisitorMailer < PlaceOS::Driver end end - # Sends any change that has been buffered for the full debounce window. - # A single sweep replaces a timer per event. + # Sends any change that has been buffered for its full debounce window. private def sweep_event_changes : Nil flush_event_changes("debounce window elapsed", older_than: Time.monotonic - @event_change_debounce.seconds) end - # Removes the matching buffered changes and dispatches each in its own fiber — - # a slow send must not stall the sweep or the shutdown drain. - # `older_than` limits the flush to entries buffered before that point (the - # sweep); nil flushes the whole buffer (the lifecycle drain). - # `wait` bounds how long we block for the sends to complete (the driver - # manager tears the module down ~6s into on_unload); nil returns immediately. + # Dispatches matching changes, each in its own fiber so a slow send can't stall + # the sweep. `older_than` limits the flush to entries buffered before that point + # (nil takes the lot), `wait` bounds how long we block for the sends to finish. private def flush_event_changes(reason : String, older_than : Time::Span? = nil, wait : Time::Span? = nil) : Nil flushing = @pending_event_changes_lock.synchronize do ready = if cutoff = older_than @@ -1190,26 +1179,20 @@ class Place::VisitorMailer < PlaceOS::Driver end # A staff/event/changed change buffered awaiting a debounced flush. - # `current_*` track the latest values seen in the burst, `previous_*` are kept - # from the first signal so the email describes the net change of the edit. + # `current_*` follow the latest signal in the burst, `previous_*` and + # `first_seen` stay as they were when it started, so the email describes the + # net change of the whole edit. class PendingEventChange - # the calendar event being edited, also the buffer key - property event_id : String - # the room the event currently sits in (latest signal) - property system_id : String + property event_id : String # also the buffer key + property system_id : String # the room the event sits in property event_ical_uid : String? - # the current host, required to render and reply-to the email property host : String property title : String? - # latest event timing seen in the burst property current_start : Int64 property current_end : Int64 - # event timing before the edit, from the first signal in the burst property previous_start : Int64? property previous_end : Int64? - # the room before the edit, from the first signal in the burst - property previous_system_id : String? - # when the burst started; the debounce window is measured from here + property previous_system_id : String? # the room before the edit getter first_seen : Time::Span = Time.monotonic def initialize( @@ -1226,9 +1209,7 @@ class Place::VisitorMailer < PlaceOS::Driver ) end - # Advance to the latest values seen in the burst. `first_seen` and the - # `previous_*` values stay as they were when the burst started, so the email - # always describes the net change of the whole edit. + # Advance to the latest signal in the burst. def merge(change : PendingEventChange) : Nil @system_id = change.system_id @event_ical_uid = change.event_ical_uid diff --git a/drivers/place/visitor_mailer_spec.cr b/drivers/place/visitor_mailer_spec.cr index 7861f49596..6c574be3f5 100644 --- a/drivers/place/visitor_mailer_spec.cr +++ b/drivers/place/visitor_mailer_spec.cr @@ -1804,8 +1804,8 @@ DriverSpecs.mock_driver "Place::VisitorMailer" do sleep 1.0 system(:Mailer)[:send_count].should eq count_before_debounce - # After the window closes the burst collapses into a single email. The sweep - # runs on an interval, so allow the debounce plus one sweep interval. + # After the window closes the burst collapses into a single email. + # Allow the debounce plus one sweep interval. sleep 6.0 system(:Mailer)[:send_count].should eq count_before_debounce + 1 system(:Mailer)[:last_to].should eq "visitor@external.com" @@ -1817,9 +1817,8 @@ DriverSpecs.mock_driver "Place::VisitorMailer" do debounce_args["previous_event_date"].should eq Time.unix(wed_start).in(gmt).to_s("%A, %-d %B") # ------------------------------------------------------------------ - # Test 38b: a change buffered when the settings are updated keeps its - # window and is still swept out afterwards, rather than being - # dropped or emailed early. + # Test 38b: a settings update mid-window neither drops the buffered + # change nor emails it early — the new sweep picks it up. # ------------------------------------------------------------------ survives_signal = { @@ -1843,7 +1842,6 @@ DriverSpecs.mock_driver "Place::VisitorMailer" do sleep 1.0 system(:Mailer)[:send_count].should eq count_before_survives - # Settings update mid-window: the buffer survives and the new sweep picks it up. settings({ timezone: "GMT", booking_space_name: "Client Floor", @@ -1851,7 +1849,7 @@ DriverSpecs.mock_driver "Place::VisitorMailer" do event_change_debounce: 3, }) - # The update must not cut the window short either. + # the update must not cut the window short sleep 0.5 system(:Mailer)[:send_count].should eq count_before_survives @@ -1865,10 +1863,9 @@ DriverSpecs.mock_driver "Place::VisitorMailer" do survives_args["previous_event_date"].should eq Time.unix(wed_start).in(gmt).to_s("%A, %-d %B") # ------------------------------------------------------------------ - # Test 38c: turning the debounce off flushes whatever is buffered — - # no sweep will run to pick it up. This is the same flush the - # driver runs from on_unload, which the spec harness cannot - # invoke directly. + # Test 38c: turning the debounce off flushes whatever is buffered, as no + # sweep will run to pick it up. Same flush as on_unload, which + # the spec harness cannot invoke directly. # ------------------------------------------------------------------ settings({ From 91c4e51be52f76094479d36c02985d0a64eb9cbd Mon Sep 17 00:00:00 2001 From: Mia Bennett Date: Mon, 27 Jul 2026 17:02:10 +0930 Subject: [PATCH 7/7] fix(visitor_mailer): debounce event changes per ical uid (PPT-2375) MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit Key the coalescing buffer on the ical uid, falling back to the event id. The signalled event id belongs to the metadata row, so it differs between the rooms either side of a move and between duplicate rows for one room — an edit that moved the meeting and changed its time sent an email per room. Grouping on the event instance collapses them into one. Merging across rooms means the room the email names has to be chosen: only a signal that reports the move advances it, so the old room's echo of the time change can't steal it back whichever order they arrive in. --- drivers/place/visitor_mailer.cr | 38 +++++-- drivers/place/visitor_mailer_readme.md | 5 + drivers/place/visitor_mailer_spec.cr | 146 ++++++++++++++++++++++++- 3 files changed, 177 insertions(+), 12 deletions(-) diff --git a/drivers/place/visitor_mailer.cr b/drivers/place/visitor_mailer.cr index 50102e8b0d..fe3ec62aac 100644 --- a/drivers/place/visitor_mailer.cr +++ b/drivers/place/visitor_mailer.cr @@ -163,7 +163,7 @@ class Place::VisitorMailer < PlaceOS::Driver # Coalescing buffer for staff/event/changed, swept once the window elapses. # seconds to buffer a change; 0 emails on every signal @event_change_debounce : Int32 = 15 - # event_id => coalesced change awaiting its flush + # ical_uid (or event_id) => coalesced change awaiting its flush @pending_event_changes : Hash(String, PendingEventChange) = {} of String => PendingEventChange @pending_event_changes_lock : Mutex = Mutex.new @@ -812,12 +812,14 @@ class Place::VisitorMailer < PlaceOS::Driver end # Collapses the burst of signals for one edit into a single buffered change. + # Keyed by event instance, so the rooms either side of a move coalesce too; + # the one email then names a single room and uses that room's guest list. private def buffer_event_change(change : PendingEventChange) : Nil @pending_event_changes_lock.synchronize do - if pending = @pending_event_changes[change.event_id]? + if pending = @pending_event_changes[change.buffer_key]? pending.merge(change) else - @pending_event_changes[change.event_id] = change + @pending_event_changes[change.buffer_key] = change end end end @@ -837,7 +839,7 @@ class Place::VisitorMailer < PlaceOS::Driver else @pending_event_changes.values end - ready.each { |pending| @pending_event_changes.delete(pending.event_id) } + ready.each { |pending| @pending_event_changes.delete(pending.buffer_key) } ready end return if flushing.empty? @@ -883,10 +885,9 @@ class Place::VisitorMailer < PlaceOS::Driver previous_system_id = change.previous_system_id # Skip a coalesced no-op (e.g. an A->B->A flip-flop that nets to no change). - changed = false + changed = change.moved_room? changed = true if (previous_start = change.previous_start) && previous_start != change.current_start changed = true if (previous_end = change.previous_end) && previous_end != change.current_end - changed = true if previous_system_id && previous_system_id != system_id return unless changed current_building_name = building_zone.display_name.presence || building_zone.name @@ -900,7 +901,7 @@ class Place::VisitorMailer < PlaceOS::Driver previous_building_name = current_building_name previous_room_name = current_room_name - if (prev_sys_id = previous_system_id) && prev_sys_id != system_id + if change.moved_room? && (prev_sys_id = previous_system_id) # Use "unknown" as the room fallback so a failed lookup surfaces in the # email rather than silently showing the current room name. previous_room_name, previous_building_name = resolve_system_location_names(prev_sys_id, "unknown", current_building_name) @@ -1183,7 +1184,7 @@ class Place::VisitorMailer < PlaceOS::Driver # `first_seen` stay as they were when it started, so the email describes the # net change of the whole edit. class PendingEventChange - property event_id : String # also the buffer key + property event_id : String property system_id : String # the room the event sits in property event_ical_uid : String? property host : String @@ -1194,6 +1195,9 @@ class Place::VisitorMailer < PlaceOS::Driver property previous_end : Int64? property previous_system_id : String? # the room before the edit getter first_seen : Time::Span = Time.monotonic + # ical_uid identifies the event instance across mailbox copies and rooms; + # event_id is only a fallback for a signal that omits it. + getter buffer_key : String def initialize( @event_id, @@ -1207,12 +1211,24 @@ class Place::VisitorMailer < PlaceOS::Driver @previous_end, @previous_system_id, ) + @buffer_key = @event_ical_uid.presence || @event_id end - # Advance to the latest signal in the burst. + # Whether this signal reports the event changing rooms. + def moved_room? : Bool + !!previous_system_id.try { |previous| previous != system_id } + end + + # Advance to the latest signal in the burst. The room only moves when a + # signal reports the move, so a same-room echo from another mailbox can't + # steal it back. def merge(change : PendingEventChange) : Nil - @system_id = change.system_id - @event_ical_uid = change.event_ical_uid + if change.moved_room? + @event_id = change.event_id + @system_id = change.system_id + @previous_system_id ||= change.previous_system_id + end + @event_ical_uid = change.event_ical_uid || @event_ical_uid @host = change.host @title = change.title @current_start = change.current_start diff --git a/drivers/place/visitor_mailer_readme.md b/drivers/place/visitor_mailer_readme.md index 2404426885..8980ee0981 100644 --- a/drivers/place/visitor_mailer_readme.md +++ b/drivers/place/visitor_mailer_readme.md @@ -47,6 +47,11 @@ delay is the configured debounce plus up to one sweep interval (at most 5s). Any still buffered is emailed immediately when the driver is unloaded, or when the debounce is turned off, so a restart never silently drops a pending notification. +Signals are grouped by event instance (its ical uid), not by room, so an edit that +moves the meeting *and* changes the time sends one email describing both rather than +one per room. A move between buildings is handled by two separate mailer modules and +so still sends an email each. + ## Reply-To Visitor emails set a `Reply-To` header so replies reach a useful person rather than diff --git a/drivers/place/visitor_mailer_spec.cr b/drivers/place/visitor_mailer_spec.cr index 6c574be3f5..8a738fa43d 100644 --- a/drivers/place/visitor_mailer_spec.cr +++ b/drivers/place/visitor_mailer_spec.cr @@ -179,6 +179,9 @@ class StaffAPIMock < DriverSpecs::MockDriver case id when "sys-room1" {id: "sys-room1", name: "Room 1", display_name: "Conference Room 1", map_id: nil, zones: ["zone-building", "zone-room"]} + when "sys-room2" + # second room in the SAME building, so signals for it pass the zone filter + {id: "sys-room2", name: "Room 2", display_name: "Conference Room 2", map_id: nil, zones: ["zone-building", "zone-room2"]} when "sys-old-room" {id: "sys-old-room", name: "Room 202", display_name: "Old Conference Room 202", map_id: nil, zones: ["zone-old-building", "zone-old-room"]} when "sys-error" @@ -1863,7 +1866,148 @@ DriverSpecs.mock_driver "Place::VisitorMailer" do survives_args["previous_event_date"].should eq Time.unix(wed_start).in(gmt).to_s("%A, %-d %B") # ------------------------------------------------------------------ - # Test 38c: turning the debounce off flushes whatever is buffered, as no + # Test 38d: the burst is keyed on the ical uid, so two signals for the + # same event instance coalesce even when they report different + # event ids (mailbox copies / duplicate metadata rows). + # ------------------------------------------------------------------ + + count_before_ical = system(:Mailer)[:send_count].as_i + + publish("staff/event/changed", { + action: "update", + system_id: "sys-room1", + event_id: "evt-copy-a", + event_ical_uid: "ical-shared", + host: "host@example.com", + resource: "room1@example.com", + title: "Shared Ical", + event_start: thu_start, + event_end: thu_start + 1800, + zones: ["zone-building", "zone-room"], + previous_event_start: wed_start, + previous_event_end: wed_start + 1800, + }.to_json) + + publish("staff/event/changed", { + action: "update", + system_id: "sys-room1", + event_id: "evt-copy-b", + event_ical_uid: "ical-shared", + host: "host@example.com", + resource: "room1@example.com", + title: "Shared Ical", + event_start: thu_start, + event_end: thu_start + 1800, + zones: ["zone-building", "zone-room"], + previous_event_start: wed_start, + previous_event_end: wed_start + 1800, + }.to_json) + + sleep 1.0 + system(:Mailer)[:send_count].should eq count_before_ical + + sleep 6.0 + system(:Mailer)[:send_count].should eq count_before_ical + 1 + system(:Mailer)[:last_args]["event_title"].should eq "Shared Ical" + + # ------------------------------------------------------------------ + # Test 38e: a room move paired with a time change. The old room's + # mailbox echoes the time change against itself; merged with + # the move it must not steal the room back. Move signal first. + # ------------------------------------------------------------------ + + count_before_move = system(:Mailer)[:send_count].as_i + + publish("staff/event/changed", { + action: "update", + system_id: "sys-room1", + event_id: "evt-move-new", + event_ical_uid: "ical-move", + host: "host@example.com", + resource: "room1@example.com", + title: "Moved And Rescheduled", + event_start: thu_start, + event_end: thu_start + 1800, + zones: ["zone-building", "zone-room"], + previous_event_start: wed_start, + previous_event_end: wed_start + 1800, + previous_system_id: "sys-room2", + }.to_json) + + publish("staff/event/changed", { + action: "update", + system_id: "sys-room2", + event_id: "evt-move-old", + event_ical_uid: "ical-move", + host: "host@example.com", + resource: "room2@example.com", + title: "Moved And Rescheduled", + event_start: thu_start, + event_end: thu_start + 1800, + zones: ["zone-building", "zone-room2"], + previous_event_start: wed_start, + previous_event_end: wed_start + 1800, + previous_system_id: "sys-room2", + }.to_json) + + sleep 7.0 + system(:Mailer)[:send_count].should eq count_before_move + 1 + system(:Mailer)[:last_to].should eq "visitor@external.com" + + move_args = system(:Mailer)[:last_args] + move_args["room_name"].should eq "Conference Room 1" + move_args["previous_room_name"].should eq "Conference Room 2" + move_args["event_date"].should eq Time.unix(thu_start).in(gmt).to_s("%A, %-d %B") + move_args["previous_event_date"].should eq Time.unix(wed_start).in(gmt).to_s("%A, %-d %B") + + # ------------------------------------------------------------------ + # Test 38f: the same pair in the other order — echo first, then the + # move — must produce the identical email. + # ------------------------------------------------------------------ + + count_before_move_echo = system(:Mailer)[:send_count].as_i + + publish("staff/event/changed", { + action: "update", + system_id: "sys-room2", + event_id: "evt-move2-old", + event_ical_uid: "ical-move-2", + host: "host@example.com", + resource: "room2@example.com", + title: "Echo First", + event_start: thu_start, + event_end: thu_start + 1800, + zones: ["zone-building", "zone-room2"], + previous_event_start: wed_start, + previous_event_end: wed_start + 1800, + previous_system_id: "sys-room2", + }.to_json) + + publish("staff/event/changed", { + action: "update", + system_id: "sys-room1", + event_id: "evt-move2-new", + event_ical_uid: "ical-move-2", + host: "host@example.com", + resource: "room1@example.com", + title: "Echo First", + event_start: thu_start, + event_end: thu_start + 1800, + zones: ["zone-building", "zone-room"], + previous_event_start: wed_start, + previous_event_end: wed_start + 1800, + previous_system_id: "sys-room2", + }.to_json) + + sleep 7.0 + system(:Mailer)[:send_count].should eq count_before_move_echo + 1 + + move_echo_args = system(:Mailer)[:last_args] + move_echo_args["room_name"].should eq "Conference Room 1" + move_echo_args["previous_room_name"].should eq "Conference Room 2" + + # ------------------------------------------------------------------ + # Test 38g: turning the debounce off flushes whatever is buffered, as no # sweep will run to pick it up. Same flush as on_unload, which # the spec harness cannot invoke directly. # ------------------------------------------------------------------