CUNY Academic Commons

Luke, I just checked the Group Email Subscription log for the specific forum topic and it looks like the entire sendout took 1hr 20mins to complete.

The activity ID for the topic is 706761. Here's the log in GMT:

[rhoh@ldv2 files]$ grep 706761 bpges-debug.log
[06-Oct-2020 11:02:19] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:33:28] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:33:28] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:33:29] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:33:31] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:33:33] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:33:33] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:33:34] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:33:36] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:33:38] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:33:38] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:33:40] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:33:41] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:33:43] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:33:43] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:33:44] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:33:45] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:33:47] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:38:17] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:38:17] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:38:19] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:38:20] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:38:23] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:38:23] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:38:23] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:38:25] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:38:27] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:38:27] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:38:29] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:38:29] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:38:31] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:38:31] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:38:33] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:38:35] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:38:37] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:43:22] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:43:24] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:43:25] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:43:25] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:43:27] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:43:29] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:43:30] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:43:30] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:43:31] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:43:33] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:43:35] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:43:36] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:43:36] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:43:38] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:43:40] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:43:40] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:43:42] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:48:18] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:48:18] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:48:18] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:48:20] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:48:22] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:48:22] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:48:23] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:48:24] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:48:27] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:48:27] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:48:27] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:48:29] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:48:32] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:48:32] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:48:33] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:48:33] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:48:37] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:53:21] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:53:23] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:53:25] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:53:25] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:53:26] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:53:27] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:53:30] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:53:30] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:53:31] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:53:32] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:53:34] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:53:35] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:53:35] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:53:37] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:53:39] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:53:39] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:53:40] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:58:18] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:58:18] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:58:19] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:58:20] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:58:23] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:58:23] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:58:24] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:58:25] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:58:27] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:58:27] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:58:29] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:58:30] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:58:33] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:58:33] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:58:33] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:58:33] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 11:58:37] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:03:28] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:03:28] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:03:29] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:03:30] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:03:32] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:03:34] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:03:34] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:03:35] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:03:38] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:03:38] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:03:39] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:03:40] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:03:42] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:03:44] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:03:44] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:03:45] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:03:47] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:08:17] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:08:19] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:08:19] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:08:20] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:08:22] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:08:24] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:08:25] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:08:25] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:08:27] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:08:29] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:08:29] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:08:29] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:08:31] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:08:33] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:08:34] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:08:34] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:08:36] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:13:21] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:13:23] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:13:24] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:13:25] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:13:26] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:13:28] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:13:28] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:13:30] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:13:30] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:13:32] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:13:34] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:13:34] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:13:35] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:13:37] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:13:39] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:13:40] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:13:40] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:18:17] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:18:17] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:18:18] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:18:19] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:18:23] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:18:23] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:18:23] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:18:25] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:18:27] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:18:27] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:18:28] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:18:29] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:18:32] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:18:33] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:18:33] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:18:34] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:18:37] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:23:21] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:23:24] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:23:25] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:23:25] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:23:25] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:23:29] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:23:29] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:23:29] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:23:29] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:23:33] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:23:34] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:23:34] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:23:34] Beginning batch of immediate notifications for 706761.
[06-Oct-2020 12:23:35] Finished sending immediate notifications for 706761. A total of 1 notifications were sent over all batches.

It looks like there was a big gap between the first batch and the second batch and I'm not sure why.

Matt posted another instance of a delay occurring here: https://redmine.gc.cuny.edu/issues/13429#note-11

I'll quote his post:

Hi Ray and Boone -- I'm not sure whether this is related, but in this thread, it sounds like the original poster is saying that a post by email he sent a while ago was only just now posted -- https://commons.gc.cuny.edu/groups/gis-working-group/forum/topic/having-issues-opening-gis/ . Is this something that is/will be addressed by the fixes you've made, or is this potentially a new issue?

My findings below:

The "having issues opening GIS" topic looks like it was posted by email. Here's the RBE log in GMT:

[08-Oct-2020 20:49:41] Subject - having issues opening GIS
[08-Oct-2020 20:49:41] Message #1: bbPress topic successfully posted!
[08-Oct-2020 20:49:49] - Webhook parsing completed -

The activity item ID for the forum topic is 707828.

I checked our Group Email Subscription log to see when it sent out the forum post. Here's the log in GMT:

[08-Oct-2020 20:49:43] Beginning batch of immediate notifications for 707828.                                                       
[08-Oct-2020 20:49:49] Finished sending immediate notifications for 707828. A total of 93 notifications were sent over all batches. 

So everything looks right on our end.

Next, I checked the mail log (postfix.log) for David, the original poster of the forum topic, and here are the relevant entries for the time period:

(Log is in Eastern Time, I believe)

Oct  8 19:47:09 lw2a postfix/smtp[65913]: 76AD6204CFC9: to=<davids_email>, relay=relay.gc.cuny.edu[172.29.28.155]:25, conn_use=5, delay=0.23, delays=0.01/0/0/0.22,
dsn=2.6.0, status=sent (250 2.6.0 <svN05WEKmYtVaeF5dgGDAOV5gMn534rdX1ndAgTo@commons.gc.cuny.edu> [InternalId=148245091189779, Hostname=WD5A.gc.cuny.edu] Queued mail for delivery)

Oct  8 20:41:36 lw2a postfix/smtp[98048]: 5C7FF204CFC9: to=<davids_email>, relay=relay.gc.cuny.edu[172.29.28.157]:25, conn_use=18, delay=0.25, delays=0/0/0/0.24, ds
n=2.6.0, status=sent (250 2.6.0 <fE30e2E8cA9NkxiOB6VImpze674XiNKa9i7REtN8@commons.gc.cuny.edu> [InternalId=148889336284270, Hostname=wd5c.gc.cuny.edu] Queued mail for delivery)

There was close to a three hour delay.

My thoughts now are that the GC's mail server is delaying or throttling the sending of Commons mail, probably due to the sheer volume that we send.

Perhaps the next step is to check the postfix settings and to contact IT to see what can be done?

Okay. If we need to contact IT, do you feel comfortable doing so, Boone and Ray? Please cc me, of course, and please write to itservices@gc.cuny.edu, cc'ing Lihua.

Ray, would you mind writing something to itservices@gc.cuny.edu, ccing Lihua (and me and Matt and Colin), summarizing your findings? I assume that Lihua can help with problems specific to postfix on the Commons server, and he will be able to help us with broader questions about outgoing email.

I've just sent the email to itservices@gc.cuny.edu. Hopefully, it's something that can be optimized and configured from postfix.

However, it might be the case that since the switch to online learning, the number of outgoing emails has increased a lot and the mail server has to throttle to prevent being blacklisted. Just a guess at the moment.