1 (edited by craig 2018-10-08 04:49:17)

Topic: mlmmj subscription emails missing

==== REQUIRED BASIC INFO OF YOUR IREDMAIL SERVER ====
- iRedMail version (check /etc/iredmail-release): 0.9.8
- Linux/BSD distribution name and version: CentOS 7.5
- Store mail accounts in which backend (LDAP/MySQL/PGSQL): MariaDB
- Web server (Apache or Nginx): Nginx
- Manage mail accounts with iRedAdmin-Pro?: Yes
- [IMPORTANT] Related original log or error message is required if you're experiencing an issue.
====

Hi Zhang,

I set up an mlmmj mailing list and added subscribers, leaving the "Send email to new members for subscription confirm" check box checked. I subscribed four addresses, two hosted on the same server (different domains) and two hosted on external servers. The subscription confirmation emails to the two external server were delivered, but the two (and a third I have since tried) to addresses hosted on the same server have bounced, even though I have double-checked and copied and pasted and successfully sent test messages to the addresses that bounced.

Here is the maillog for one of the addresses:

Oct  7 20:21:39 my postfix/10025/smtpd[21160]: connect from my.server.net[127.0.0.1]
Oct  7 20:21:39 my postfix/10025/smtpd[21160]: 4C239C5A3E0: client=my.server.net[127.0.0.1]
Oct  7 20:21:39 my postfix/cleanup[22786]: 4C239C5A3E0: message-id=<1538943699-24101-mlmmj-7b047c2b@example.com>
Oct  7 20:21:39 my postfix/10025/smtpd[21160]: disconnect from my.server.net[127.0.0.1]
Oct  7 20:21:39 my postfix/qmgr[24863]: 4C239C5A3E0: from=<test20181007+bounces-confsub-416f6d79443aa0d4-craig=example.net@example.com>, size=2115, nrcpt=1 (queue active)
Oct  7 20:21:39 my amavis[21484]: (21484-15) Passed CLEAN {RelayedInternal}, MLMMJ LOCAL [127.0.0.1] <test20181007+bounces-confsub-416f6d79443aa0d4-craig=example.net@example.com> -> <craig@example.net>, Message-ID: <1538943699-24101-mlmmj-7b047c2b@example.com>, mail_id: tGqaDISvmU4W, Hits: -, size: 1065, queued_as: 4C239C5A3E0, dkim_new=dkim:mail.myserver.com, 87 ms
Oct  7 20:21:39 my amavis[21484]: (21484-15) Passed CLEAN, <test20181007+bounces-confsub-416f6d79443aa0d4-craig=example.net@example.com> -> <craig@example.net>, Hits: -, tag=0, tag2=0, kill=0, queued_as: 4C239C5A3E0, L/0/0/0
Oct  7 20:21:39 my postfix/pipe[23475]: 4C239C5A3E0: to=<craig@example.net>, relay=dovecot, delay=0.02, delays=0/0/0/0.02, dsn=5.1.1, status=bounced (user unknown)
Oct  7 20:21:39 my postfix/cleanup[22783]: 514CCC5A3E2: message-id=<20181007202139.514CCC5A3E2@my.server.net>
Oct  7 20:21:39 my postfix/qmgr[24863]: 514CCC5A3E2: from=<>, size=4099, nrcpt=1 (queue active)
Oct  7 20:21:39 my postfix/bounce[24104]: 4C239C5A3E0: sender non-delivery notification: 514CCC5A3E2
Oct  7 20:21:39 my postfix/qmgr[24863]: 4C239C5A3E0: removed
Oct  7 20:21:39 my postfix/pipe[24105]: 514CCC5A3E2: to=<test20181007+bounces-confsub-416f6d79443aa0d4-craig=example.net@example.com>, relay=mlmmj, delay=0.01, delays=0/0.01/0/0, dsn=2.0.0, status=sent (delivered via mlmmj service)
Oct  7 20:21:39 my postfix/qmgr[24863]: 514CCC5A3E2: removed

The "Received Mails" log in iRedAdmin-Pro also shows that the message was received. (See attachment.)

With reference to the maillog output, the mailing list is test20181007@example.COM and I have tried to subscribe craig@example.NET. Both domains are hosted on the same (iRedMail, of course) server. The maillog output says "status=bounced (user unknown)" for craig@example.NET. However, it absolutely *DOES* exist, as I've explained above, and does not bounce incoming messages from externally hosted domains or domains hosted on the same server.

Thanks in advance for your assistance.


Craig

Post's attachments

20181007_received_mlmmj_email_redacted.png
20181007_received_mlmmj_email_redacted.png 7.43 kb, 1 downloads since 2018-10-07 

You don't have the permssions to download the attachments of this post.

----

Spider Email Archiver: On-Premises, lightweight email archiving software developed by iRedMail team. Supports Amazon S3 compatible storage and custom branding.

2

Re: mlmmj subscription emails missing

Additionally, I now have zombie mlmmj processes running for some reason:

[08:09:44 root@server ~]# ps aux --sort start_time|grep -i mlmmj
mlmmj     1196  0.0  0.0 230904  3928 ?        Ss   Jun06   5:00 /usr/sbin/uwsgi --ini /opt/mlmmjadmin/rc_scripts/uwsgi/rhel.ini --pidfile /var/run/mlmmjadmin/mlmmjadmin.pid
mlmmj     1275  0.0  0.0 233896  6020 ?        S    Jun06   0:00 /usr/sbin/uwsgi --ini /opt/mlmmjadmin/rc_scripts/uwsgi/rhel.ini --pidfile /var/run/mlmmjadmin/mlmmjadmin.pid
mlmmj     1277  0.0  0.0 233896  5496 ?        S    Jun06   0:00 /usr/sbin/uwsgi --ini /opt/mlmmjadmin/rc_scripts/uwsgi/rhel.ini --pidfile /var/run/mlmmjadmin/mlmmjadmin.pid
mlmmj     1278  0.0  0.0 233896  6056 ?        S    Jun06   0:00 /usr/sbin/uwsgi --ini /opt/mlmmjadmin/rc_scripts/uwsgi/rhel.ini --pidfile /var/run/mlmmjadmin/mlmmjadmin.pid
mlmmj     1279  0.0  0.0 233896  5276 ?        S    Jun06   0:00 /usr/sbin/uwsgi --ini /opt/mlmmjadmin/rc_scripts/uwsgi/rhel.ini --pidfile /var/run/mlmmjadmin/mlmmjadmin.pid
mlmmj     1280  0.0  0.0 233896  5100 ?        S    Jun06   0:00 /usr/sbin/uwsgi --ini /opt/mlmmjadmin/rc_scripts/uwsgi/rhel.ini --pidfile /var/run/mlmmjadmin/mlmmjadmin.pid
mlmmj     7989  0.0  0.0      0     0 ?        Z    Oct07   0:00 [mlmmj-send] <defunct>
mlmmj     7990  0.0  0.0      0     0 ?        Z    Oct07   0:00 [mlmmj-send] <defunct>
mlmmj     7991  0.0  0.0      0     0 ?        Z    Oct07   0:00 [mlmmj-send] <defunct>
mlmmj     7992  0.0  0.0      0     0 ?        Z    Oct07   0:00 [mlmmj-send] <defunct>
mlmmj    23736  0.0  0.0      0     0 ?        Z    Oct07   0:00 [mlmmj-send] <defunct>
mlmmj    24101  0.0  0.0      0     0 ?        Z    Oct07   0:00 [mlmmj-send] <defunct>
root     25641  0.0  0.0 112704   996 pts/0    S+   08:11   0:00 grep --color=auto -i mlmmj
[08:11:34 root@server ~]#

This hasn't been an issue until now, even though there is another mlmmj list running on this server. Is this a known issue?


Craig

3

Re: mlmmj subscription emails missing

Any ideas on this Zhang? I *really* need to get this working properly very soon.


Craig

4

Re: mlmmj subscription emails missing

Try to stop service and check how many processes are running.

As per

/opt/mlmmjadmin/rc_scripts/uwsgi/rhel.ini

value of processes is defined (default 5), so that many processes will be active.

And in your case:

is user craig@example.net exist? log shows user unknown check if dovecot is getting proper results if user actually exist:

Oct  7 20:21:39 my postfix/pipe[23475]: 4C239C5A3E0: to=<craig@example.net>, relay=dovecot, delay=0.02, delays=0/0/0/0.02, dsn=5.1.1, status=bounced (user unknown)

5

Re: mlmmj subscription emails missing

Thanks for trying to help, but I posted in the PRO forum because I'm looking for support from the PRO creator and maintainer of the PRO software. I doubt that zombie processes are defined anywhere, and the answer to your question is contained in my original post.

6

Re: mlmmj subscription emails missing

craig wrote:

Oct  7 20:21:39 my postfix/pipe[23475]: 4C239C5A3E0: to=<craig@example.net>, relay=dovecot, delay=0.02, delays=0/0/0/0.02, dsn=5.1.1, status=bounced (user unknown)

This means Postfix piped email to Dovecot LDA, but Dovecot can NOT find this user by sql/ldap query. It's not related to mlmmj in this case (according to this log line).

You need to turn on debug mode in Dovecot and try again, then find related log from Dovecot log files for troubleshooting.

FYI: http://www.iredmail.org/docs/debug.dovecot.html

7

Re: mlmmj subscription emails missing

Thanks Zhang. Thanks for your reply. This is all I see in /var/log/dovecot/dovecot.log after turning on debug mode, restarting Dovecot and trying to add craig@example.net as a member of the list:

[18:12:26 root@server dovecot]# grep craig@example.net dovecot.log
Oct 11 18:10:36 server dovecot: lda(craig@example.net): Debug: Loading modules from directory: /usr/lib64/dovecot
Oct 11 18:10:36 server dovecot: lda(craig@example.net): Debug: Module loaded: /usr/lib64/dovecot/lib01_acl_plugin.so
Oct 11 18:10:36 server dovecot: lda(craig@example.net): Debug: Module loaded: /usr/lib64/dovecot/lib10_quota_plugin.so
Oct 11 18:10:36 server dovecot: lda(craig@example.net): Debug: Module loaded: /usr/lib64/dovecot/lib15_notify_plugin.so
Oct 11 18:10:36 server dovecot: lda(craig@example.net): Debug: Module loaded: /usr/lib64/dovecot/lib20_mail_log_plugin.so
Oct 11 18:10:36 server dovecot: lda(craig@example.net): Debug: Module loaded: /usr/lib64/dovecot/lib20_mailbox_alias_plugin.so
Oct 11 18:10:36 server dovecot: lda(craig@example.net): Debug: Module loaded: /usr/lib64/dovecot/lib90_sieve_plugin.so
Oct 11 18:10:36 server dovecot: lda(craig@example.net): Debug: Module loaded: /usr/lib64/dovecot/lib90_stats_plugin.so
Oct 11 18:10:36 server dovecot: lda(craig@example.net): Debug: auth USER input:
[18:12:31 root@server dovecot]#

Anywhere else I should be looking?

Just to clarify, all of the users and mailing lists involved were added through iRedAdmin-Pro.


Craig

8

Re: mlmmj subscription emails missing

You should send a new testing email to get log related to your issue.

9

Re: mlmmj subscription emails missing

ZhangHuangbin wrote:

You should send a new testing email to get log related to your issue.

Hi Zhang, I did. That's it above.

10

Re: mlmmj subscription emails missing

Hi Craig,

We need full log, not filtered with 'grep'. Important info may be removed by grep.

In Dovecot debug log, when you send an email to a mailing list, Dovecot should perform SQL query to get sql records of the member, and i expect to see the SQL commands Dovecot performed, also the output (generated by Dovecot).

11 (edited by craig 2018-10-15 18:32:24)

Re: mlmmj subscription emails missing

Hi Zhang,

Thanks for your reply. OK, so you want me to paste the whole 285 MB dovecot.log here? That can't be right. You must need something less than that but more than what I filtered through grep.


Craig

12

Re: mlmmj subscription emails missing

In the meantime I have added the two problem users and bypassed the need for them to confirm their subscriptions, since the confirmation emails bounce.

13

Re: mlmmj subscription emails missing

craig wrote:

Thanks for your reply. OK, so you want me to paste the whole 285 MB dovecot.log here? That can't be right. You must need something less than that but more than what I filtered through grep.

Hi Craig, I just need the log relevant to your latest testing email.

if you give me un-relevant log, it will confuse me and waste a lot my time. so just relevant log please.

14

Re: mlmmj subscription emails missing

Hi Zhang,

Of course, but you're not telling me what the relevant log is and how I'm supposed to get it. Sorry. I don't want to waste your time with 285 MB of irrelevant logs.


Craig

15

Re: mlmmj subscription emails missing

Let me put it another way: If I actually gave you 285 MB of logs, what would *you* look for? A date and time? An email address? A particular SQL query? A script name? If you can tell me that then I'll narrow it down to a few consecutive lines instead of 285 MB.

16

Re: mlmmj subscription emails missing

About relevant log, what i mean is log got with steps below:

1) Run "tail -f /var/log/maillog" (or other log file which is involved in your issue)
2) Send test email to trigger the issue
3) Copy all output of the command in step 1). This is relevant log.

If some other log file involved, do it the same way.

17

Re: mlmmj subscription emails missing

OK, first, I'm confused why you would tell me to turn on debug mode for Dovecot, but ask for output from maillog (especially as that's what I provided in my original post), but here it is:

[01:05:45 root@server log]# tail -f maillog
Oct 19 01:08:30 server postfix/smtpd[13443]: connect from subscriber1.server[1.2.3.4]
Oct 19 01:08:31 server postfix/smtpd[13443]: Anonymous TLS connection established from subscriber1.server[1.2.3.4]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Oct 19 01:08:31 server postfix/smtpd[13443]: A818FC547F1: client=subscriber1.server[1.2.3.4]
Oct 19 01:08:31 server postfix/cleanup[12598]: A818FC547F1: message-id=<1539911288.2698.34.camel@wrathall>
Oct 19 01:08:31 server postfix/qmgr[24863]: A818FC547F1: from=<subscriber1@external-domain.com>, size=2303, nrcpt=1 (queue active)
Oct 19 01:08:31 server postfix/10025/smtpd[13423]: connect from mlmmj.server[127.0.0.1]
Oct 19 01:08:31 server postfix/10025/smtpd[13423]: F002BC547F3: client=mlmmj.server[127.0.0.1]
Oct 19 01:08:31 server postfix/cleanup[12826]: F002BC547F3: message-id=<1539911288.2698.34.camel@wrathall>
Oct 19 01:08:31 server postfix/10025/smtpd[13423]: disconnect from mlmmj.server[127.0.0.1]
Oct 19 01:08:31 server postfix/qmgr[24863]: F002BC547F3: from=<subscriber1@external-domain.com>, size=2855, nrcpt=1 (queue active)
Oct 19 01:08:31 server amavis[6364]: (06364-17) Passed CLEAN {RelayedInbound}, [1.2.3.4]:58130 [24.86.239.82] <subscriber1@external-domain.com> -> <test20181007@mlmmj-domain.com>, Queue-ID: A818FC547F1, Message-ID: <1539911288.2698.34.camel@wrathall>, mail_id: k1VSeKeJwcJI, Hits: -, size: 2303, queued_as: F002BC547F3, dkim_sd=dkim:mail.external-domain.com, 83 ms
Oct 19 01:08:31 server amavis[6364]: (06364-17) Passed CLEAN, <subscriber1@external-domain.com> -> <test20181007@mlmmj-domain.com>, Hits: -, tag=-100, tag2=3.5, kill=3.5, queued_as: F002BC547F3, L/Y/0/0
Oct 19 01:08:31 server postfix/amavis/smtp[13064]: A818FC547F1: to=<test20181007@mlmmj-domain.com>, relay=127.0.0.1[127.0.0.1]:10024, delay=0.42, delays=0.33/0/0/0.09, dsn=2.0.0, status=sent (250 2.0.0 from MTA(smtp:[127.0.0.1]:10025): 250 2.0.0 Ok: queued as F002BC547F3)
Oct 19 01:08:31 server postfix/qmgr[24863]: A818FC547F1: removed
Oct 19 01:08:32 server postfix/pipe[13468]: F002BC547F3: to=<test20181007@mlmmj-domain.com>, relay=mlmmj, delay=0.02, delays=0/0.01/0/0.01, dsn=2.0.0, status=sent (delivered via mlmmj service)
Oct 19 01:08:32 server postfix/qmgr[24863]: F002BC547F3: removed
Oct 19 01:08:32 server postfix/10025/smtpd[13351]: 0A8B7C547F1: client=mlmmj.server[127.0.0.1]
Oct 19 01:08:32 server postfix/cleanup[12598]: 0A8B7C547F1: message-id=<1539911288.2698.34.camel@wrathall>
Oct 19 01:08:32 server postfix/10025/smtpd[13351]: disconnect from mlmmj.server[127.0.0.1]
Oct 19 01:08:32 server postfix/qmgr[24863]: 0A8B7C547F1: from=<test20181007+bounces-2-subscriber1=external-domain.com@mlmmj-domain.com>, size=4069, nrcpt=1 (queue active)
Oct 19 01:08:32 server amavis[11837]: (11837-06) Passed CLEAN {RelayedInternal}, MLMMJ LOCAL [127.0.0.1] [24.86.239.82] <test20181007+bounces-2-subscriber1=external-domain.com@mlmmj-domain.com> -> <subscriber1@external-domain.com>, Message-ID: <1539911288.2698.34.camel@wrathall>, mail_id: Dk0HH2Sv2IoY, Hits: -, size: 3068, queued_as: 0A8B7C547F1, dkim_new=dkim:mail.iredmail.server, 44 ms
Oct 19 01:08:32 server amavis[11837]: (11837-06) Passed CLEAN, <test20181007+bounces-2-subscriber1=external-domain.com@mlmmj-domain.com> -> <subscriber1@external-domain.com>, Hits: -, tag=0, tag2=0, kill=0, queued_as: 0A8B7C547F1, L/0/0/0
Oct 19 01:08:32 server postfix/smtpd[13443]: disconnect from subscriber1.server[1.2.3.4]
Oct 19 01:08:32 server postfix/10025/smtpd[12964]: connect from mlmmj.server[127.0.0.1]
Oct 19 01:08:32 server postfix/10025/smtpd[12964]: 2019DC547F3: client=mlmmj.server[127.0.0.1]
Oct 19 01:08:32 server postfix/cleanup[12826]: 2019DC547F3: message-id=<1539911288.2698.34.camel@wrathall>
Oct 19 01:08:32 server postfix/qmgr[24863]: 2019DC547F3: from=<test20181007+bounces-2-subscriber2=shaw.ca@mlmmj-domain.com>, size=4065, nrcpt=1 (queue active)
Oct 19 01:08:32 server amavis[11837]: (11837-06-2) Passed CLEAN {RelayedInternal}, MLMMJ LOCAL [127.0.0.1] [24.86.239.82] <test20181007+bounces-2-subscriber2=shaw.ca@mlmmj-domain.com> -> <subscriber2@shaw.ca>, Message-ID: <1539911288.2698.34.camel@wrathall>, mail_id: mysNGXnY0qMh, Hits: -, size: 3068, queued_as: 2019DC547F3, dkim_new=dkim:mail.iredmail.server, 84 ms
Oct 19 01:08:32 server amavis[11837]: (11837-06-2) Passed CLEAN, <test20181007+bounces-2-subscriber2=shaw.ca@mlmmj-domain.com> -> <subscriber2@shaw.ca>, Hits: -, tag=0, tag2=0, kill=0, queued_as: 2019DC547F3, L/0/0/0
Oct 19 01:08:32 server postfix/smtpd[13445]: disconnect from unknown[196.201.19.50]
Oct 19 01:08:32 server postfix/10025/smtpd[12964]: 34928C547F6: client=mlmmj.server[127.0.0.1]
Oct 19 01:08:32 server postfix/cleanup[12598]: 34928C547F6: message-id=<1539911288.2698.34.camel@wrathall>
Oct 19 01:08:32 server postfix/qmgr[24863]: 34928C547F6: from=<test20181007+bounces-2-subscriber3=gmail.com@mlmmj-domain.com>, size=4069, nrcpt=1 (queue active)
Oct 19 01:08:32 server amavis[11837]: (11837-06-3) Passed CLEAN {RelayedInternal}, MLMMJ LOCAL [127.0.0.1] [24.86.239.82] <test20181007+bounces-2-subscriber3=gmail.com@mlmmj-domain.com> -> <subscriber3@gmail.com>, Message-ID: <1539911288.2698.34.camel@wrathall>, mail_id: rQwZiunY1OVn, Hits: -, size: 3068, queued_as: 34928C547F6, dkim_new=dkim:mail.iredmail.server, 80 ms
Oct 19 01:08:32 server amavis[11837]: (11837-06-3) Passed CLEAN, <test20181007+bounces-2-subscriber3=gmail.com@mlmmj-domain.com> -> <subscriber3@gmail.com>, Hits: -, tag=0, tag2=0, kill=0, queued_as: 34928C547F6, L/0/0/0
Oct 19 01:08:32 server postfix/10025/smtpd[12964]: 492A4C547F7: client=mlmmj.server[127.0.0.1]
Oct 19 01:08:32 server postfix/cleanup[12826]: 492A4C547F7: message-id=<1539911288.2698.34.camel@wrathall>
Oct 19 01:08:32 server postfix/qmgr[24863]: 492A4C547F7: from=<test20181007+bounces-2-susan=example.com@mlmmj-domain.com>, size=4079, nrcpt=1 (queue active)
Oct 19 01:08:32 server amavis[11837]: (11837-06-4) Passed CLEAN {RelayedInternal}, MLMMJ LOCAL [127.0.0.1] [24.86.239.82] <test20181007+bounces-2-susan=example.com@mlmmj-domain.com> -> <susan@example.com>, Message-ID: <1539911288.2698.34.camel@wrathall>, mail_id: rhcmHtxkqev8, Hits: -, size: 3068, queued_as: 492A4C547F7, dkim_new=dkim:mail.iredmail.server, 80 ms
Oct 19 01:08:32 server amavis[11837]: (11837-06-4) Passed CLEAN, <test20181007+bounces-2-susan=example.com@mlmmj-domain.com> -> <susan@example.com>, Hits: -, tag=0, tag2=0, kill=0, queued_as: 492A4C547F7, L/0/0/0
Oct 19 01:08:32 server postfix/pipe[13335]: 492A4C547F7: to=<susan@example.com>, relay=dovecot, delay=0.03, delays=0/0/0/0.02, dsn=5.1.1, status=bounced (user unknown)
Oct 19 01:08:32 server postfix/cleanup[12598]: 4F26BC547F9: message-id=<20181019010832.4F26BC547F9@mlmmj.server>
Oct 19 01:08:32 server postfix/bounce[13481]: 492A4C547F7: sender non-delivery notification: 4F26BC547F9
Oct 19 01:08:32 server postfix/qmgr[24863]: 4F26BC547F9: from=<>, size=6048, nrcpt=1 (queue active)
Oct 19 01:08:32 server postfix/qmgr[24863]: 492A4C547F7: removed
Oct 19 01:08:32 server postfix/pipe[13468]: 4F26BC547F9: to=<test20181007+bounces-2-susan=example.com@mlmmj-domain.com>, relay=mlmmj, delay=0.01, delays=0/0/0/0.01, dsn=2.0.0, status=sent (delivered via mlmmj service)
Oct 19 01:08:32 server postfix/qmgr[24863]: 4F26BC547F9: removed
Oct 19 01:08:32 server postfix/10025/smtpd[12964]: 5DC87C547F7: client=mlmmj.server[127.0.0.1]
Oct 19 01:08:32 server postfix/cleanup[12826]: 5DC87C547F7: message-id=<1539911288.2698.34.camel@wrathall>
Oct 19 01:08:32 server postfix/qmgr[24863]: 5DC87C547F7: from=<test20181007+bounces-2-craig=example.net@mlmmj-domain.com>, size=4061, nrcpt=1 (queue active)
Oct 19 01:08:32 server amavis[11837]: (11837-06-5) Passed CLEAN {RelayedInternal}, MLMMJ LOCAL [127.0.0.1] [24.86.239.82] <test20181007+bounces-2-craig=example.net@mlmmj-domain.com> -> <craig@example.net>, Message-ID: <1539911288.2698.34.camel@wrathall>, mail_id: TydeR49PvNwe, Hits: -, size: 3068, queued_as: 5DC87C547F7, dkim_new=dkim:mail.iredmail.server, 82 ms
Oct 19 01:08:32 server amavis[11837]: (11837-06-5) Passed CLEAN, <test20181007+bounces-2-craig=example.net@mlmmj-domain.com> -> <craig@example.net>, Hits: -, tag=0, tag2=0, kill=0, queued_as: 5DC87C547F7, L/0/0/0
Oct 19 01:08:32 server postfix/pipe[13335]: 5DC87C547F7: to=<craig@example.net>, relay=dovecot, delay=0.02, delays=0/0/0/0.01, dsn=5.1.1, status=bounced (user unknown)
Oct 19 01:08:32 server postfix/cleanup[12598]: 62438C547F9: message-id=<20181019010832.62438C547F9@mlmmj.server>
Oct 19 01:08:32 server postfix/bounce[13481]: 5DC87C547F7: sender non-delivery notification: 62438C547F9
Oct 19 01:08:32 server postfix/qmgr[24863]: 62438C547F9: from=<>, size=5976, nrcpt=1 (queue active)
Oct 19 01:08:32 server postfix/qmgr[24863]: 5DC87C547F7: removed
Oct 19 01:08:32 server postfix/pipe[13468]: 62438C547F9: to=<test20181007+bounces-2-craig=example.net@mlmmj-domain.com>, relay=mlmmj, delay=0.01, delays=0/0/0/0.01, dsn=2.0.0, status=sent (delivered via mlmmj service)
Oct 19 01:08:32 server postfix/qmgr[24863]: 62438C547F9: removed
Oct 19 01:08:34 server postfix/smtp[13352]: Untrusted TLS connection established to smtp.glb.shawcable.net[64.59.136.136]:25: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
Oct 19 01:08:34 server postfix/submission/smtpd[13496]: connect from unknown[102.149.192.55]
Oct 19 01:08:35 server postfix/smtp[13352]: 2019DC547F3: to=<subscriber2@shaw.ca>, relay=smtp.glb.shawcable.net[64.59.136.136]:25, delay=3.5, delays=0/0/2.6/0.94, dsn=2.0.0, status=sent (250 2.0.0 DJHEgPnSQ85hUDJHGgYF6n mail accepted for delivery)
Oct 19 01:08:35 server postfix/qmgr[24863]: 2019DC547F3: removed
^C
[01:08:52 root@server log]#

These are the relevant details:

* List address: test20181007@mlmmj-domain.com
* Subscribers:
    * subscriber1@external-domain.com
    * subscriber2@shaw.ca
    * subscriber3@gmail.com
    * susan@example.com
    * craig@example.net
* Locally hosted domains:
    * example.com
    * example.net
* Test message was sent by subscriber1@external-domain.com.

One more time, susan@example.com and craig@example.net **DO** exist and send and receive email multiple times a day. There are **NO** spelling mistakes.

18

Re: mlmmj subscription emails missing

Hi craig,

Can you turn on debug mode on dovecot and fetch respective logs? Please do the same testing and get dovecot logs.

19

Re: mlmmj subscription emails missing

Thanks again, but I'll wait to hear from Zhang ... unless you're willing to explain how you think you can help. I'm very confused by your intervention in this thread.

20

Re: mlmmj subscription emails missing

craig wrote:

OK, first, I'm confused why you would tell me to turn on debug mode for Dovecot, but ask for output from maillog (especially as that's what I provided in my original post), but here it is:

Sorry about the confusion.

I need both Postfix and Dovecot (debug) log. As mentioned in my previous reply, "1) Run "tail -f /var/log/maillog" (or other log file which is involved in your issue)", dovecot is required also.

For Postfix log, i need to check whether the mail flow is correctly handled by Postfix/Amavisd/mlmmj, for Dovecot, i need to check whether the SQL queries are correct and the query results.

Like @ketan.aagja said, you still need to turn on debug mode in Dovecot, then do this testing again, and extract relevant log of your testing email from Dovecot log file.

21

Re: mlmmj subscription emails missing

Hi Zhang,

Thanks for your reply. I did turn on debug mode when you told me to, and the output in dovecot.log is (as far as I can see) exactly what I gave you on the 12th (default PunBB time):

[01:13:53 root@server dovecot]# pwd
/var/log/dovecot
[01:14:12 root@server dovecot]# grep "Oct 19 01:08:" *.log
dovecot.log:Oct 19 01:08:32 server dovecot: lda(susan@example.com): Debug: Loading modules from directory: /usr/lib64/dovecot
dovecot.log:Oct 19 01:08:32 server dovecot: lda(susan@example.com): Debug: Module loaded: /usr/lib64/dovecot/lib01_acl_plugin.so
dovecot.log:Oct 19 01:08:32 server dovecot: lda(susan@example.com): Debug: Module loaded: /usr/lib64/dovecot/lib10_quota_plugin.so
dovecot.log:Oct 19 01:08:32 server dovecot: lda(susan@example.com): Debug: Module loaded: /usr/lib64/dovecot/lib15_notify_plugin.so
dovecot.log:Oct 19 01:08:32 server dovecot: lda(susan@example.com): Debug: Module loaded: /usr/lib64/dovecot/lib20_mail_log_plugin.so
dovecot.log:Oct 19 01:08:32 server dovecot: lda(susan@example.com): Debug: Module loaded: /usr/lib64/dovecot/lib20_mailbox_alias_plugin.so
dovecot.log:Oct 19 01:08:32 server dovecot: lda(susan@example.com): Debug: Module loaded: /usr/lib64/dovecot/lib90_sieve_plugin.so
dovecot.log:Oct 19 01:08:32 server dovecot: lda(susan@example.com): Debug: Module loaded: /usr/lib64/dovecot/lib90_stats_plugin.so
dovecot.log:Oct 19 01:08:32 server dovecot: lda(susan@example.com): Debug: auth USER input:
dovecot.log:Oct 19 01:08:32 server dovecot: lda(craig@example.net): Debug: Loading modules from directory: /usr/lib64/dovecot
dovecot.log:Oct 19 01:08:32 server dovecot: lda(craig@example.net): Debug: Module loaded: /usr/lib64/dovecot/lib01_acl_plugin.so
dovecot.log:Oct 19 01:08:32 server dovecot: lda(craig@example.net): Debug: Module loaded: /usr/lib64/dovecot/lib10_quota_plugin.so
dovecot.log:Oct 19 01:08:32 server dovecot: lda(craig@example.net): Debug: Module loaded: /usr/lib64/dovecot/lib15_notify_plugin.so
dovecot.log:Oct 19 01:08:32 server dovecot: lda(craig@example.net): Debug: Module loaded: /usr/lib64/dovecot/lib20_mail_log_plugin.so
dovecot.log:Oct 19 01:08:32 server dovecot: lda(craig@example.net): Debug: Module loaded: /usr/lib64/dovecot/lib20_mailbox_alias_plugin.so
dovecot.log:Oct 19 01:08:32 server dovecot: lda(craig@example.net): Debug: Module loaded: /usr/lib64/dovecot/lib90_sieve_plugin.so
dovecot.log:Oct 19 01:08:32 server dovecot: lda(craig@example.net): Debug: Module loaded: /usr/lib64/dovecot/lib90_stats_plugin.so
dovecot.log:Oct 19 01:08:32 server dovecot: lda(craig@example.net): Debug: auth USER input:
[01:14:42 root@server dovecot]#

There was no relevant output in imap.log, lda.log, pop3.log and sieve.log. This is for the exact same time frame as the Postfix log above, which all took place within 60 seconds. I followed the instructions at https://docs.iredmail.org/debug.dovecot.html to turn on debugging and restarted Dovecot:

[01:34:42 root@server dovecot]# pwd
/etc/dovecot
[01:34:45 root@server dovecot]# ls -la
total 52
drwxr-xr-x.  3 root    root      198 Oct 11 18:00 .
drwxr-xr-x. 92 root    root     8192 Jun  6 03:10 ..
drwxr-xr-x.  2 root    root     4096 May  6 00:37 conf.d
-rw-rw-r--.  1 root    root    12619 Oct 11 18:00 dovecot.conf
-rw-r--r--.  1 root    root     4380 May  6 00:40 dovecot.conf.2018.05.06.00.37.26
-r-x------.  1 dovecot dovecot     0 May  6 00:40 dovecot-master-users
-r-xr-x---.  1 root    root     1092 May  6 00:40 dovecot-mysql.conf
-r-x------.  1 dovecot dovecot   515 May  6 00:40 dovecot-share-folder.conf
-r-x------.  1 dovecot dovecot   344 May  6 00:40 dovecot-used-quota.conf
[01:34:47 root@server dovecot]# grep debug dovecot.conf
mail_debug = yes
#auth_debug = yes
#auth_debug_passwords = yes
[01:35:19 root@server dovecot]# systemctl status dovecot
? dovecot.service - Dovecot IMAP/POP3 email server
   Loaded: loaded (/usr/lib/systemd/system/dovecot.service; enabled; vendor preset: disabled)
   Active: active (running) since Thu 2018-10-11 18:00:53 UTC; 1 weeks 1 days ago
     Docs: man:dovecot(1)
           http://wiki2.dovecot.org/
  Process: 19802 ExecStop=/usr/bin/doveadm stop (code=exited, status=0/SUCCESS)
  Process: 19810 ExecStart=/usr/sbin/dovecot (code=exited, status=0/SUCCESS)
  Process: 19807 ExecStartPre=/usr/libexec/dovecot/prestartscript (code=exited, status=0/SUCCESS)
 Main PID: 19813 (dovecot)
   CGroup: /system.slice/dovecot.service
           +- 3120 dovecot/imap-login
           +- 3121 dovecot/imap

<<snip>>

As for @ketan.aagja, I don't know who he is and what connection he has to you and iRedMail/iRedAdmin-Pro. In the iRedMail forum there are people helping each other because it's based on open source products, but in the "iRedAdmin-Pro Support" I'm only expecting to deal with you.

Thanks.


Craig

22

Re: mlmmj subscription emails missing

Try this: run SQL commands below to export SQL record of user "craig@example.net":

USE vmail;
SELECT * FROM mailbox WHERE username='craig@example.net' LIMIT 1 \G

Note: use '\G' instead of ';' at the end please, it will be easier for me to read.

craig wrote:

As for @ketan.aagja, I don't know who he is and what connection he has to you and iRedMail/iRedAdmin-Pro. In the iRedMail forum there are people helping each other because it's based on open source products, but in the "iRedAdmin-Pro Support" I'm only expecting to deal with you.

I'm very glad that someone else like @ketan.aagja steps in to help answer the questions, i suggest you be open to other minds. smile

23

Re: mlmmj subscription emails missing

Zhang, craig@example.net is an alias for craig1234@example.net, therefore there is no output for the SQL you gave me.

Here is the output for the actual address:

MariaDB [vmail]> SELECT * FROM mailbox WHERE username='craig1234@example.net' LIMIT 1 \G
*************************** 1. row ***************************
                username: craig1234@example.net
                password: $1$kTmYM799$cmqsOC4EzdoZebwB8RNV/.
                    name:
                language: en_US
    storagebasedirectory: /var/vmail
             storagenode: vmail1
                 maildir: example.net/c/r/a/craig1234-2013.10.15.20.43.10/
                   quota: 2048
                  domain: example.net
               transport:
              department:
                    rank: normal
              employeeid:
                 isadmin: 0
           isglobaladmin: 0
              enablesmtp: 1
       enablesmtpsecured: 1
              enablepop3: 1
       enablepop3secured: 1
              enableimap: 1
       enableimapsecured: 1
           enabledeliver: 1
               enablelda: 1
       enablemanagesieve: 1
enablemanagesievesecured: 1
             enablesieve: 1
      enablesievesecured: 1
          enableinternal: 1
           enabledoveadm: 1
       enablelib-storage: 1
           lastlogindate: 1970-01-01 01:01:01
           lastloginipv4: 0
       lastloginprotocol:
              disclaimer:
      passwordlastchange: 1970-01-01 01:01:01
          allowedsenders:
         rejectedsenders:
       allowedrecipients:
      rejectedrecipients:
                 created: 2013-10-15 20:43:10
                modified: 2018-09-10 05:47:44
                 expired: 9999-12-31 00:00:00
                  active: 1
                   bytes: 0
                messages: 0
              enablelmtp: 1
                settings:
    enableindexer-worker: 1
              allow_nets: NULL
           enableimaptls: 1
           enablepop3tls: 1
          enablesievetls: 1
             enabledsync: 1
              enablesogo: 1
1 row in set (0.00 sec)
ZhangHuangbin wrote:

I'm very glad that someone else like @ketan.aagja steps in to help answer the questions, i suggest you be open to other minds. smile

My mind is open to people who are interested in helping if they state clearly how they intend to help and it is clear to me that they have the qualifications to help. His two posts show that he cannot or did not actually read and understand my posts, which led me to conclude he was not qualified to help.

24

Re: mlmmj subscription emails missing

craig wrote:

Zhang, craig@example.net is an alias for craig1234@example.net, therefore there is no output for the SQL you gave me.

Then you should use craig1234@ as member.

is it a per-user alias address? Show me output of SQL commands below please:

USE vmail;
SELECT address,forwarding,is_maillist,is_list,is_forwarding,is_alias FROM forwardings WHERE address IN ('craig@example.net', 'craig1234@example.net') OR forwarding IN ('craig@example.net', 'craig1234@example.net') \G

25

Re: mlmmj subscription emails missing

ZhangHuangbin wrote:
craig wrote:

Zhang, craig@example.net is an alias for craig1234@example.net, therefore there is no output for the SQL you gave me.

Then you should use craig1234@ as member.

That doesn't make sense. craig@example.net is my email address, not craig1234@example.net. It's what I give to everyone I communicate with. It works for messages sent from external *and* internal sources in 100% of cases ... except this one, which means this is a bug.

ZhangHuangbin wrote:

is it a per-user alias address?

I think "aliases" are sometime misnamed in iRedAdmin-Pro; sometimes aliases are actually *forwarders*. In this case I believe craig@example.net is actually a true alias of craig1234@example.net -- i.e., it is entered at "All domains/example.net/Users/Profile of user: craig1234@example.net/Aliases".

ZhangHuangbin wrote:

Show me output of SQL commands below please:

USE vmail;
SELECT address,forwarding,is_maillist,is_list,is_forwarding,is_alias FROM forwardings WHERE address IN ('craig@example.net', 'craig1234@example.net') OR forwarding IN ('craig@example.net', 'craig1234@example.net') \G

There are 25 rows for addresses on several different domains from which email is *forwarded* to craig@example.net. In case there's something you need I have included all output, but to keep things simple I have changed all addresses on domains not involved to other@foreigndomain.com. I believe that only rows 1 and 2 are relevant.

MariaDB [(none)]> use vmail;
Reading table information for completion of table and column names
You can turn off this feature to get a quicker startup with -A

Database changed
MariaDB [vmail]> SELECT address,forwarding,is_maillist,is_list,is_forwarding,is_alias FROM forwardings WHERE address IN ('craig@example.net', 'craig1234@example.net') OR forwarding IN ('craig@example.net', 'craig1234@example.net') \G
*************************** 1. row ***************************
      address: craig1234@example.net
   forwarding: craig1234@example.net
  is_maillist: 0
      is_list: 0
is_forwarding: 1
     is_alias: 0
*************************** 2. row ***************************
      address: craig@example.net
   forwarding: craig1234@example.net
  is_maillist: 0
      is_list: 0
is_forwarding: 0
     is_alias: 1
*************************** 3. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 4. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 5. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 6. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 7. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 8. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 9. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 10. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 11. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 0
is_forwarding: 1
     is_alias: 0
*************************** 12. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 0
is_forwarding: 1
     is_alias: 0
*************************** 13. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 0
is_forwarding: 1
     is_alias: 0
*************************** 14. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 15. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 16. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 17. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 18. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 19. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 20. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 21. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 0
is_forwarding: 1
     is_alias: 0
*************************** 22. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 23. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 24. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
*************************** 25. row ***************************
      address: other@foreigndomain.com
   forwarding: craig@example.net
  is_maillist: 0
      is_list: 1
is_forwarding: 0
     is_alias: 0
25 rows in set (0.00 sec)

Craig