# Users receive multiple summary emails when sidekiq queue is \>30 minutes

**URL:** https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291
**Category:** Self-hosting
**Created:** [3월 21, 2019, 10:15오후 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291 "2019-03-21T22:15:00Z")
**Posts on this page:** 20
**Page:** 1

<div class="post-metadata">

### Author: ![pfaffman](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/pfaffman/32/120154_2.png) [@pfaffman](https://meta.discourse.org/u/pfaffman)
#### Post date: [3월 21, 2019, 10:15오후 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/1 "2019-03-21T22:15:00Z")

</div>

I’ve got a [high-volume system with 24GB ram, a 30GB on disk database, and 2M page views/month](https://meta.discourse.org/t/expected-99th-percentile-performance/111924/2). There were some bumps as the site got migrated and updated to the new image format, but last I looked it appeared to be running smoothly according to those familiar with the site.

Earlier today I noticed 25K sidekiq jobs. They got processed pretty quickly, but sidekiq reported a 10Ks latency.

A user reported that they had received 5 summary emails in the space of an hour. Here’s the mail-sent graph:

 ![image](https://global.discourse-cdn.com/meta/original/3X/2/8/283257d5755b251eedf16cd104dd092c0f13227b.png)

Here’s grafana stats for the day.

 ![image](https://global.discourse-cdn.com/meta/original/3X/3/7/37bbb9cc820b758fbd374aa97596493fff9a00ed.png)

The site was upgraded a couple days back when I installed the prometheus exporter plugin.

There were complaints of multiple summary emails earlier, but I chalked that up to the site being swamped due to the image processing.

Does anyone have an explanation for why a user might receive multiple summary emails in a day?

---

<div class="post-metadata">

### Author: ![pfaffman](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/pfaffman/32/120154_2.png) [@pfaffman](https://meta.discourse.org/u/pfaffman)
#### Post date: [3월 21, 2019, 10:28오후 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/2 "2019-03-21T22:28:16Z")

</div>

~~I found a user who has weekly summaries set in their settings. That user received 3-7 summary emails per day over the past few days.~~

Edit: No I didn’t. But I did find a user who was sent four digests today (in that list of 300 messages):

 ![image](https://global.discourse-cdn.com/meta/original/3X/e/2/e2660e1958a83883351fd1827c63d41ea53c8f49.png)

Here’s the query in case I did something stupid:

```plaintext
SELECT user_id, created_at
from email_logs 
WHERE email_type='digest'
AND created_at > now() - interval '4 day' 
ORDER BY user_id, created_at DESC
LIMIT 300

```

There are more than a dozen users with 3-6 digests today.

---

<div class="post-metadata">

### Author: ![codinghorror](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/codinghorror/32/110067_2.png) [@codinghorror](https://meta.discourse.org/u/codinghorror)
#### Post date: [3월 22, 2019, 6:44오전 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/3 "2019-03-22T06:44:17Z")

</div>

Database corruption, maybe? We have no other systemic reports of digest emails going out inappropriately.

Did you check and make sure this user doesn’t have anything weird in their user settings for the activity summary (aka “digest”)

 ![image](https://global.discourse-cdn.com/meta/original/3X/4/1/41d2deffdd0b1ad152cda6816194c5069fe782ad.png)

---

<div class="post-metadata">

### Author: ![pfaffman](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/pfaffman/32/120154_2.png) [@pfaffman](https://meta.discourse.org/u/pfaffman)
#### Post date: [3월 22, 2019, 9:27오전 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/4 "2019-03-22T09:27:29Z")

</div>

The ones I inspected had “weekly” checked.

I can have a closer look at the rails console.

Any other idea of what kind of corruption could cause this?

.

---

<div class="post-metadata">

### Author: ![codinghorror](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/codinghorror/32/110067_2.png) [@codinghorror](https://meta.discourse.org/u/codinghorror)
#### Post date: [3월 22, 2019, 9:28오전 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/5 "2019-03-22T09:28:41Z")

</div>

Zero idea but we have no other reports of this, so it’s specific to the migration or config somehow.

Could there be multiple instances running or multiple sidekiqs or anything bizarre like that? 🤷‍♂️

---

<div class="post-metadata">

### Author: ![pfaffman](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/pfaffman/32/120154_2.png) [@pfaffman](https://meta.discourse.org/u/pfaffman)
#### Post date: [3월 22, 2019, 9:38오전 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/6 "2019-03-22T09:38:44Z")

</div>

Something like multiple sidekiq is something I considered, or somehow sidekiq is slow so it (or postgres) doesn’t report that the digest has been created when it checks again?

Remember that we were concerned about disk performance. Is it possible that postgres could somehow not commit that the digest has been sent and another one gets started before the last one gets finished?

I’ll double check that there isn’t somehow an extra container running somehow.

EDIT: I see just the data, web, and mail-receiver containers.

I checked the mail logs for the user that complained. There were four digests yesterday:

```plaintext
  created_at: Thu, 21 Mar 2019 15:11:33 UTC +00:00,
  created_at: Thu, 21 Mar 2019 15:58:46 UTC +00:00,
  created_at: Thu, 21 Mar 2019 17:15:29 UTC +00:00,
  created_at: Thu, 21 Mar 2019 18:35:39 UTC +00:00,

```

Each took had the same time for `created_at` as `updated_at`. UserOptions look normal.

```
  digest_after_minutes: 10080,

```

---

<div class="post-metadata">

### Author: ![pfaffman](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/pfaffman/32/120154_2.png) [@pfaffman](https://meta.discourse.org/u/pfaffman)
#### Post date: [3월 22, 2019, 11:38오전 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/7 "2019-03-22T11:38:35Z")

</div>

I think I’ve identified a race condition. I know that the sidekiq queue had a 10K second (~3 hour) latency. Messages are queued every 30 minutes:

> <https://github.com/discourse/discourse/blob/main/app/jobs/scheduled/enqueue_digest_emails.rb#L3-L4>

So a digest gets queued in an hour-long queue. Half an hour later we test for whether to queue another digest, checking the last time that a message was sent:

> <https://github.com/discourse/discourse/blob/main/app/jobs/scheduled/enqueue_digest_emails.rb#L22>

The last digest is **queued** , but not **sent** , so `last_emailed_at` isn’t updated, so another message gets queued.

The solutions that I see are:

1. this site gets faster hardware (beyond my control)
2. `target_user_ids` somehow searches the queue to see if there is a queued, unsent digest (seems really hard and won’t get into core in my lifetime).
3. Have the process that **sends** the digest do another check of `last_emailed_at` before sending the digest (I think this might be the best long-term solution, but haven’t found that code)
4. I add a hook to modify `enqueue_digest_emails.rb` to make `every 30.minutes` something like `4.hours` (6 hours?) and hope that is enough time for the queue to get processed before it runs again.

Number 4 above seems like my only immediate solution. Is there some deleterious side effect that I am overlooking?

(I did recently increase `db_shared_buffers` from 10GB to 16GB for the 30GB on disk database. This might help, but I suspect that it won’t be enough. There are ~25K users at TL1 and above.)

---

<div class="post-metadata">

### Author: ![codinghorror](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/codinghorror/32/110067_2.png) [@codinghorror](https://meta.discourse.org/u/codinghorror)
#### Post date: [3월 22, 2019, 11:43오전 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/8 "2019-03-22T11:43:08Z")

</div>

Entirely plausible, I suggest running basic disk perf stats, if your disks are slow (non-SSD) and you have a lot of activity and a large database.. it isn’t going to be pretty.

---

<div class="post-metadata">

### Author: ![pfaffman](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/pfaffman/32/120154_2.png) [@pfaffman](https://meta.discourse.org/u/pfaffman)
#### Post date: [3월 22, 2019, 11:59오전 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/9 "2019-03-22T11:59:41Z")

</div>

We both know that the disk performance is insufficient. That is beyond my control.

I guess I’ll up the digest queue to 4 hours. I don’t see an alternative.

---

<div class="post-metadata">

### Author: ![neil](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/neil/32/102150_2.png) [@neil](https://meta.discourse.org/u/neil)
#### Post date: [3월 22, 2019, 1:28오후 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/10 "2019-03-22T13:28:20Z")

</div>

> [@pfaffman](#):
>
> Have the process that **sends** the digest do another check of `last_emailed_at` before sending the digest (I think this might be the best long-term solution, but haven’t found that code)

I think this is a good solution too. Summary emails (and many others) are put into the low-priority queue, so are most likely to be delayed when sidekiq has a lot of jobs to process. I don’t think it’s too much of a hack to check last\_emailed\_at if it’s a digest email in [here](https://github.com/discourse/discourse/blob/master/app/jobs/regular/user_email.rb#L18-L24).

---

<div class="post-metadata">

### Author: ![pfaffman](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/pfaffman/32/120154_2.png) [@pfaffman](https://meta.discourse.org/u/pfaffman)
#### Post date: [3월 22, 2019, 2:28오후 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/11 "2019-03-22T14:28:40Z")

</div>

Thanks, @neil. So something like

```
      return if type.to_s == "digest" && user.last_emailed_at < user.digest_after_minutes

```

right about

> <https://github.com/discourse/discourse/blob/main/app/jobs/regular/user_email.rb#L101>

?

---

<div class="post-metadata">

### Author: ![neil](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/neil/32/102150_2.png) [@neil](https://meta.discourse.org/u/neil)
#### Post date: [3월 22, 2019, 2:44오후 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/12 "2019-03-22T14:44:55Z")

</div>

Yup, that’s about right.

```ruby
return if type.to_s == "digest" &&
  user.last_emailed_at < user.user_option.digest_after_minutes.minutes.ago

```

---

<div class="post-metadata">

### Author: ![pfaffman](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/pfaffman/32/120154_2.png) [@pfaffman](https://meta.discourse.org/u/pfaffman)
#### Post date: [3월 22, 2019, 2:47오후 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/13 "2019-03-22T14:47:48Z")

</div>

Aha! `.ago`. Obvious once I see it.

Should I submit a PR for this two-liner or will it be faster for you to just do it?

---

<div class="post-metadata">

### Author: ![zogstrip](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/zogstrip/32/512781_2.png) [@zogstrip](https://meta.discourse.org/u/zogstrip)
#### Post date: [3월 22, 2019, 2:53오후 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/14 "2019-03-22T14:53:11Z")

</div>

> [@pfaffman](#):
>
> Should I submit a PR

That’d be awesome if you could also include a test 😉

---

<div class="post-metadata">

### Author: ![pfaffman](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/pfaffman/32/120154_2.png) [@pfaffman](https://meta.discourse.org/u/pfaffman)
#### Post date: [3월 22, 2019, 2:57오후 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/15 "2019-03-22T14:57:47Z")

</div>

> [@zogstrip](#):
>
> That’d be awesome if you could also include a test

Offer to give a guy an inch. . . 😉

A test, huh? Having never written one, I think it’ll take me a couple hours to pull that off. It’s not too soon for me to learn how to do that, though. Maybe next week.

---

<div class="post-metadata">

### Author: ![neil](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/neil/32/102150_2.png) [@neil](https://meta.discourse.org/u/neil)
#### Post date: [3월 22, 2019, 3:11오후 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/16 "2019-03-22T15:11:35Z")

</div>

I can do it and then you can be my accomplice if something breaks. 😛

---

<div class="post-metadata">

### Author: ![pfaffman](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/pfaffman/32/120154_2.png) [@pfaffman](https://meta.discourse.org/u/pfaffman)
#### Post date: [3월 22, 2019, 3:17오후 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/18 "2019-03-22T15:17:19Z")

</div>

I think I"m a few minutes away from figuring out how to write the test. . . but then I’ll still have to figure out how to run it.

But I’d be honored to be your accomplice.

And if you’re going to write the test, then I’ll go back to writing bash tab completion for `./launcher`. It’s been bugging me for years.

---

<div class="post-metadata">

### Author: ![neil](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/neil/32/102150_2.png) [@neil](https://meta.discourse.org/u/neil)
#### Post date: [3월 22, 2019, 3:19오후 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/19 "2019-03-22T15:19:26Z")

</div>

Turns out there’s a similar test to the one I wanted to write that has a problem… It isn’t actually testing anything, so I should fix that too.

```ruby
  it "doesn't call the mailer when the user is missing" do
    Jobs::UserEmail.new.execute(type: :digest, user_id: 1234)

    expect(ActionMailer::Base.deliveries).to eq([])
  end

```

^ Passes for valid user\_id values too.

---

<div class="post-metadata">

### Author: ![pfaffman](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/pfaffman/32/120154_2.png) [@pfaffman](https://meta.discourse.org/u/pfaffman)
#### Post date: [3월 22, 2019, 3:24오후 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/20 "2019-03-22T15:24:21Z")

</div>

> [@neil](#):
>
> Turns out there’s a similar test to the one I wanted to write that has a problem… It isn’t actually testing anything, so I should fix that too.

This is getting way above my pay grade. 🙂

---

<div class="post-metadata">

### Author: ![neil](https://sea3.discourse-cdn.com/meta/user_avatar/meta.discourse.org/neil/32/102150_2.png) [@neil](https://meta.discourse.org/u/neil)
#### Post date: [3월 22, 2019, 4:35오후 UTC](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291/21 "2019-03-22T16:35:58Z")

</div>

Fix is here:

[https://github.com/discourse/discourse/commit/399e937a38f4b4917e0c44897c308d39d4a844e1](https://github.com/discourse/discourse/commit/399e937a38f4b4917e0c44897c308d39d4a844e1)

[다음 페이지](https://meta.discourse.org/t/users-receive-multiple-summary-emails-when-sidekiq-queue-is-30-minutes/112291.md?page=2)
