Campaign Status "Finished" Before All Emails Were Sent

[kousu]

Version:

• listmonk: 4.1.0
• OS: Debian 12

Description of the bug:
If listmonk is shutdown during a running campaign it finishes the campaign, leaving some emails unsent.

This is like the previously fixed #1931, #1993, #1986 and #1546 but the exact sequence of steps is different.

Screenshots:

I started a campaign at 4:06am; my throttle is slow on my email plan so my campaigns usually take many hours to complete. I forgot I had a cronjob to reboot the system at 7:55am so listmonk shut down and when it came back I received the "Finished: NEWS 25-01-28 EN (resend for failures)" email (at 7:55!), but it had skipped sending almost 100 emails.

Logs

Jan 30 04:06:20 list.example.org listmonk[29421]: 2025/01/30 04:06:20.309284 manager.go:413: start processing campaign (NEWS 25-01-28 EN (resend for failures))
Jan 30 04:06:49 list.example.org listmonk[29421]: 2025/01/30 04:06:49.488565 pipe.go:122: messages exceeded (100) for the window (1h0m0s since 30 Jan 25 03:58 -0500). Sleeping for 51m46s.
Jan 30 05:01:16 list.example.org listmonk[29421]: 2025/01/30 05:01:16.149115 pipe.go:122: messages exceeded (100) for the window (1h0m0s since 30 Jan 25 04:58 -0500). Sleeping for 57m19s.
Jan 30 05:01:20 list.example.org listmonk[29421]: 2025/01/30 05:01:20.530509 manager.go:489: error sending message in campaign NEWS 25-01-28 EN (resend for failures): subscriber 5026: 421 too many messages in this connection
Jan 30 06:01:30 list.example.org listmonk[29421]: 2025/01/30 06:01:30.764944 pipe.go:122: messages exceeded (100) for the window (1h0m0s since 30 Jan 25 05:58 -0500). Sleeping for 57m5s.
Jan 30 06:01:35 list.example.org listmonk[29421]: 2025/01/30 06:01:35.198904 manager.go:489: error sending message in campaign NEWS 25-01-28 EN (resend for failures): subscriber 5153: 421 too many messages in this connection
Jan 30 07:01:31 list.example.org listmonk[29421]: 2025/01/30 07:01:31.943362 pipe.go:122: messages exceeded (100) for the window (1h0m0s since 30 Jan 25 06:58 -0500). Sleeping for 57m3s.
Jan 30 07:01:36 list.example.org listmonk[29421]: 2025/01/30 07:01:36.354492 manager.go:489: error sending message in campaign NEWS 25-01-28 EN (resend for failures): subscriber 5273: 421 too many messages in this connection
Jan 30 07:55:01 list.example.org systemd[1]: Stopping listmonk.service - listmonk mailing list manager...
Jan 30 07:55:02 list.example.org systemd[1]: listmonk.service: Deactivated successfully.
Jan 30 07:55:02 list.example.org systemd[1]: Stopped listmonk.service - listmonk mailing list manager.
Jan 30 07:55:02 list.example.org systemd[1]: listmonk.service: Consumed 10.120s CPU time.
-- Boot 7170c0081b0b4056b5dfbd494d55a75a --
Jan 30 07:55:24 list.example.org systemd[1]: Started listmonk.service - listmonk mailing list manager.
Jan 30 07:55:24 list.example.org listmonk[919]: 2025/01/30 07:55:24.452344 main.go:107: v4.1.0 (0a27de1 2024-11-12T18:42:26Z, linux/amd64)
Jan 30 07:55:24 list.example.org listmonk[919]: 2025/01/30 07:55:24.454229 init.go:163: reading config: /etc/listmonk/mailer.toml
Jan 30 07:55:24 list.example.org listmonk[919]: 2025/01/30 07:55:24.457746 init.go:303: connecting to db: localhost:5432/listmonk
Jan 30 07:55:25 list.example.org listmonk[919]: 2025/01/30 07:55:25.070741 init.go:652: media upload provider: filesystem
Jan 30 07:55:25 list.example.org listmonk[919]: 2025/01/30 07:55:25.142704 init.go:575: loaded email (SMTP) messenger: [email protected]@mail.yota.space
Jan 30 07:55:25 list.example.org listmonk[919]: ⇨ http server started on 127.0.0.1:9000
Jan 30 07:55:30 list.example.org listmonk[919]: 2025/01/30 07:55:30.219154 manager.go:413: start processing campaign (NEWS 25-01-28 EN (resend for failures))
Jan 30 07:55:30 list.example.org listmonk[919]: 2025/01/30 07:55:30.237813 pipe.go:217: campaign (NEWS 25-01-28 EN (resend for failures)) finished

I looked through my mail server logs and it looks like it got through email addresses starting with "A" through "R" and stopped within the "S"es.

That it says these two things immediately after restarting in quick succession can't be right:

manager.go:413: start processing campaign (NEWS 25-01-28 EN (resend for failures))
pipe.go:217: campaign (NEWS 25-01-28 EN (resend for failures)) finished

Steps to reproduce:

1. In order to slow listmonk down enough to see the bug, under Settings > Performance set

   1. Concurrency = 1
   2. Message rate = 1
   3. Enable Sliding Window and set to 10 messages in 1m

2. Create a new subscriber list and upload import.csv into it

   (created by:)

   cat /usr/share/dict/words | grep -v "'" | \
     shuf -r | head -n 100 | \
     (echo "email,name,attributes"; awk -v OFS=, '{ print $1 "@example.org", $1, "\"{}\"" }') | \
     tee import.csv
   

3. Create a campaign and assign the new list to it

4. Launch the campaign

5. Wait a couple minutes so that about 20 to 30 messages get sent

6. systemctl stop listmonk (or otherwise shut it down, using whatever daemon manager you're using)

7. systemctl start listmonk

8. You should receive the "Finished" notification, and see the "Finished" tag on the Campaigns page, but also see that only about 30/100 messages were sent.

Reproduction Screenshot

I tested these reproduction steps exactly as written and indeed I have a campaign that only got through 1/3rd of its work:

[mapreri]

This actually happened to me too today.

What's even a bit more amusing, is that the trigger for the restart came from within listmonk itself, as I was tweaking the settings to fire off the emails a little faster, and upon clicking "save" the app restarted on itself, marking the campaing as "finished". This is weird as I noticed other similar occasion did not restart the app but caused a pop-up to come out informing me to pause the campaign and then click to restart, but it did not in this occasion.

Incidentally, how could I fire off the mails to missing people now?

[kousu]

Ah cool, good to know I'm not alone :)

I don't think there is an easy way to tell who received the mails or not from within listmonk. My method is to log in to my mail relay's site and copy, page by page, the list of delivered emails. I cut them up into mails-delivered.txt, then I go to listmonk, export the list I was sending to to subscribers.csv, and then generate the set-complement with

comm -23 <(awk -v FS=, 'NR>1 { print $2 }' subscribers.csv | sort) <(cat mails-delivered.txt | sort) | (echo "email,name,attributes"; awk -v FS=, -v OFS=, '{ split($1,n,"@"); print $1,n[1],"\"{}\"" }') > missed.csv

Then I reimport that to a new list, clone the campaign, and set this list as it's target and relaunch.

It's been a time sink for me to deal with all these lost mail bugs (but I do it because listmonk feels a lot better to use than mailchimp).

Now that I'm thinking about it, listmonk has a count of sent mails so there should be a SQL query that could extract mails-delivered.txt. The longest step for me is copying off my mail relay's logs.

[alexzaganelli]

Hi @kousu , did you spot the what is issue?

[kousu]

No, I'm sorry @alexzaganelli , I haven't made time to go digging in the code.