Page 1 of 1

EFA not processing all mail

Posted: 27 Dec 2021 18:15
by francity
Hello.

My firewall is configured to forward SMTP to my eFa, which then processes and forwards to Exchange. However, it appears that all of the mail is not being processed by eFa. I cannot say how long this has been occurring, except that I was expecting a message this morning at about 06:05 am (which was CC'ed to my gmail account). The CC arrived at gmail at 06:10 am, however, the original did not arrive in Exchange.

I reviewed the log on my firewall, and realized that the issue appears to be larger than I thought, and not isolated to a single missing mail item. My 06:05 mail was not the only one I was missing from eFa. According to the firewall log, there were at least another six (6) messages which were not processed by eFa. Between 05:39 am and 07:47 am, only four (4) of 11 messages were processed by eFa (it appears that my 06:05 message tried on four (4) other occasions between 06:19 am and 06:36 am to deliver and then gave up). Below, please see an image of the firewall log, showing the times at which mail was received (I have added a column to indicate whether it was processed by eFa), as well as a screenshot of the messages from MailWatch, showing the messages that were processed.
firewall-log.png
firewall-log.png (37.62 KiB) Viewed 5534 times
mail-redacted.png
mail-redacted.png (16.83 KiB) Viewed 5534 times
Grateful for your assistance on how to resolve this issue.

My config is as follows:

- efa-4.0.4
- MailWatch Version: 1.2.18
- Operating System Version: CentOS Linux 7 (Core)
- Postfix Version: 3.5.9
- MailScanner Version: 5.4.2
- ClamAV Version: 0.103.4
- SpamAssassin Version: 3.4.6
- PHP Version: 7.4.26
- MySQL Version: 10.2.30-MariaDB

Thank you.

Kind regards,

Dale

Re: EFA not processing all mail

Posted: 30 Dec 2021 13:40
by shawniverson
There could be a number of reasons why mail isn't making into the appliance. Have you examined /var/log/maillog to see what is happening as connections are being made?

Re: EFA not processing all mail

Posted: 03 Jan 2022 04:22
by francity
Hello Shawn,

Happy New Year. Thank you for your response.

I am new to this. I reviewed the mailllog and it appears that the email in question returned an "auth=0".

Please see my redacted maillog. I tried but could not attach to the message. For ease of reference, I have inserted line numbers.

*** Beginning of logfile (324 lines) ***

1. Dec 27 05:39:57 m-gate postfix/smtpd[24072]: connect from mail.rosswan.cam[5.181.161.112]
2. Dec 27 05:39:59 m-gate postfix/smtpd[24072]: 4JMt1W31GMz9ZF8: client=mail.rosswan.cam[5.181.161.112]
3. Dec 27 05:39:59 m-gate postfix/cleanup[24079]: 4JMt1W31GMz9ZF8: message-id=<0.0.0.9.1D7FB05230B9BA2.57EFB1@mail.rosswan.cam>
4. Dec 27 05:39:59 m-gate opendkim[2832]: 4JMt1W31GMz9ZF8: mail.rosswan.cam [5.181.161.112] not internal
5. Dec 27 05:39:59 m-gate opendkim[2832]: 4JMt1W31GMz9ZF8: not authenticated
6. Dec 27 05:39:59 m-gate opendkim[2832]: 4JMt1W31GMz9ZF8: DKIM verification successful
7. Dec 27 05:40:00 m-gate opendmarc[2831]: 4JMt1W31GMz9ZF8: SPF(mailfrom): rosswan.cam pass
8. Dec 27 05:40:00 m-gate opendmarc[2831]: 4JMt1W31GMz9ZF8: rosswan.cam pass
9. Dec 27 05:40:00 m-gate MSMilter[24076]: MailWatch: Allowlist refresh time reached
10. Dec 27 05:40:00 m-gate MSMilter[24076]: MailWatch: Starting up MailWatch SQL Allowlist
11. Dec 27 05:40:00 m-gate MSMilter[24076]: MailWatch: Read 3 allowlist entries
12. Dec 27 05:40:00 m-gate MSMilter[24076]: MailWatch: Blocklist refresh time reached
13. Dec 27 05:40:00 m-gate MSMilter[24076]: MailWatch: Starting up MailWatch SQL Blocklist
14. Dec 27 05:40:00 m-gate MSMilter[24076]: MailWatch: Read 0 blocklist entries
15. Dec 27 05:40:01 m-gate postfix/cleanup[24079]: 4JMt1W31GMz9ZF8: milter-discard: END-OF-MESSAGE from mail.rosswan.cam[5.181.161.112]: milter triggers DISCARD action; from=<solarbright_floodlights_discount-xxxxxxxxxxxxxxx @rosswan.cam> to=<xxxxxxxxxxxxxxx> proto=ESMTP helo=<mail.rosswan.cam>
16. Dec 27 05:40:01 m-gate postfix/smtpd[24072]: 4JMt1Y1X1Vz9ZF8: client=mail.rosswan.cam[5.181.161.112]
17. Dec 27 05:40:01 m-gate postfix/cleanup[24079]: 4JMt1Y1X1Vz9ZF8: message-id=<0.0.0.9.1D7FB05230B9BA2.58FE69@mail.rosswan.cam>
18. Dec 27 05:40:01 m-gate opendkim[2832]: 4JMt1Y1X1Vz9ZF8: mail.rosswan.cam [5.181.161.112] not internal
19. Dec 27 05:40:01 m-gate opendkim[2832]: 4JMt1Y1X1Vz9ZF8: not authenticated
20. Dec 27 05:40:01 m-gate opendkim[2832]: 4JMt1Y1X1Vz9ZF8: DKIM verification successful
21. Dec 27 05:40:01 m-gate opendmarc[2831]: 4JMt1Y1X1Vz9ZF8: SPF(mailfrom): rosswan.cam pass
22. Dec 27 05:40:01 m-gate opendmarc[2831]: 4JMt1Y1X1Vz9ZF8: rosswan.cam pass
23. Dec 27 05:40:02 m-gate postfix/cleanup[24079]: 4JMt1Y1X1Vz9ZF8: milter-discard: END-OF-MESSAGE from mail.rosswan.cam[5.181.161.112]: milter triggers DISCARD action; from=<solarbright-floodlights-discount-xxxxxxxxxxxxxxx@rosswan.cam> to=<xxxxxxxxxxxxxxx> proto=ESMTP helo=<mail.rosswan.cam>
24. Dec 27 05:40:02 m-gate postfix/smtpd[24072]: disconnect from mail.rosswan.cam[5.181.161.112] ehlo=1 mail=2 rcpt=2 bdat=4 quit=1 commands=10
25. Dec 27 05:40:02 m-gate MailScanner[18265]: New Batch: Scanning 2 messages, 18833 bytes
26. Dec 27 05:40:02 m-gate MailScanner[18265]: Virus and Content Scanning: Starting
27. Dec 27 05:40:07 m-gate MailScanner[18265]: <A> tag found in message 4JMt1Y1X1Vz9ZF8 from solarbright-floodlights-discount-xxxxxxxxxxxxxxx@rosswan.cam
28. Dec 27 05:40:07 m-gate MailScanner[18265]: HTML Img tag found in message 4JMt1Y1X1Vz9ZF8 from solarbright-floodlights-discount-xxxxxxxxxxxxxxx@rosswan.cam
29. Dec 27 05:40:07 m-gate MailScanner[18265]: <A> tag found in message 4JMt1W31GMz9ZF8 from solarbright_floodlights_discountxxxxxxxxxxxxxxx@rosswan.cam
30. Dec 27 05:40:07 m-gate MailScanner[18265]: HTML Img tag found in message 4JMt1W31GMz9ZF8 from solarbright_floodlights_discount-xxxxxxxxxxxxxxx@rosswan.cam
31. Dec 27 05:40:07 m-gate MailScanner[18265]: Spam Checks: Starting
32. Dec 27 05:40:07 m-gate MailScanner[18265]: MailWatch: Allowlist refresh time reached
33. Dec 27 05:40:07 m-gate MailScanner[18265]: MailWatch: Starting up MailWatch SQL Allowlist
34. Dec 27 05:40:07 m-gate MailScanner[18265]: MailWatch: Read 3 allowlist entries
35. Dec 27 05:40:07 m-gate MailScanner[18265]: MailWatch: Blocklist refresh time reached
36. Dec 27 05:40:07 m-gate MailScanner[18265]: MailWatch: Starting up MailWatch SQL Blocklist
37. Dec 27 05:40:07 m-gate MailScanner[18265]: MailWatch: Read 0 blocklist entries
38. Dec 27 05:40:18 m-gate MailScanner[18265]: Message 4JMt1Y1X1Vz9ZF8 from 5.181.161.112 (solarbright-floodlights-discount-xxxxxxxxxxxxxxx@rosswan.cam) to xxxxxxxxxxxxxxx is spam, SpamAssassin (not cached, score=5.65, required 4, BAYES_80 2.00, DCC_CHECK 1.10, DKIM_SIGNED 0.10, DKIM_VALID -0.10, DKIM_VALID_AU -0.10, DKIM_VALID_EF -0.10, FROM_FMBLA_NEWDOM 1.50, HTML_MESSAGE 0.00, MIME_QP_LONG_LINE 0.00, SPF_HELO_NONE 0.00, SPF_PASS -0.00, URIBL_ABUSE_SURBL 1.25)
39. Dec 27 05:40:19 m-gate MailScanner[18265]: Message 4JMt1W31GMz9ZF8 from 5.181.161.112 (solarbright_floodlights_discount-xxxxxxxxxxxxxxx@rosswan.cam) to xxxxxxxxxxxxxxx is spam, SpamAssassin (not cached, score=6.65, required 4, BAYES_95 3.00, DCC_CHECK 1.10, DKIM_SIGNED 0.10, DKIM_VALID -0.10, DKIM_VALID_AU -0.10, DKIM_VALID_EF -0.10, FROM_FMBLA_NEWDOM 1.50, HTML_MESSAGE 0.00, MIME_QP_LONG_LINE 0.00, SPF_HELO_NONE 0.00, SPF_PASS -0.00, URIBL_ABUSE_SURBL 1.25)
40. Dec 27 05:40:19 m-gate MailScanner[18265]: Spam Checks: Found 2 spam messages
41. Dec 27 05:40:19 m-gate MailScanner[18265]: Spam Actions: message 4JMt1Y1X1Vz9ZF8 actions are store
42. Dec 27 05:40:19 m-gate MailScanner[18265]: Spam Actions: message 4JMt1W31GMz9ZF8 actions are store
43. Dec 27 05:40:19 m-gate MailScanner[18265]: MailWatch: Logging message 4JMt1Y1X1Vz9ZF8 to SQL
44. Dec 27 05:40:19 m-gate MailScanner[18265]: MailWatch: Logging message 4JMt1W31GMz9ZF8 to SQL
45. Dec 27 05:43:22 m-gate postfix/anvil[24073]: statistics: max connection rate 1/60s for (smtp:5.181.161.112) at Dec 27 05:39:57
46. Dec 27 05:43:22 m-gate postfix/anvil[24073]: statistics: max connection count 1 for (smtp:5.181.161.112) at Dec 27 05:39:57
47. Dec 27 05:43:22 m-gate postfix/anvil[24073]: statistics: max cache size 1 at Dec 27 05:39:57
48. Dec 27 06:02:48 m-gate postfix/smtpd[27075]: connect from unknown[193.56.29.119]
49. Dec 27 06:02:51 m-gate postfix/smtpd[27075]: disconnect from unknown[193.56.29.119] ehlo=1 auth=0/1 rset=1 quit=1 commands=3/4
50. Dec 27 06:06:12 m-gate postfix/anvil[27076]: statistics: max connection rate 1/60s for (smtp:193.56.29.119) at Dec 27 06:02:48
51. Dec 27 06:06:12 m-gate postfix/anvil[27076]: statistics: max connection count 1 for (smtp:193.56.29.119) at Dec 27 06:02:48
52. Dec 27 06:06:12 m-gate postfix/anvil[27076]: statistics: max cache size 1 at Dec 27 06:02:48
53. Dec 27 06:19:49 m-gate postfix/smtpd[29306]: connect from unknown[193.56.29.119]
54. Dec 27 06:19:54 m-gate postfix/smtpd[29306]: disconnect from unknown[193.56.29.119] ehlo=1 auth=0/1 rset=1 quit=1 commands=3/4
55. Dec 27 06:20:11 m-gate postfix/smtpd[29306]: connect from mail.veriomta.com[104.216.54.230]
56. Dec 27 06:20:12 m-gate postfix/smtpd[29306]: NOQUEUE: reject: RCPT from mail.veriomta.com[104.216.54.230]: 554 5.7.1 Service unavailable; Client host [104.216.54.230] blocked using zen.spamhaus.org; https://www.spamhaus.org/sbl/query/SBLCSS; from=<doctors.warning-xxxxxxxxxxxxxxx@graplithium.com> to=<xxxxxxxxxxxxxxx> proto=ESMTP helo=<mail.graplithium.com>
57. Dec 27 06:20:13 m-gate postfix/smtpd[29306]: disconnect from mail.veriomta.com[104.216.54.230] ehlo=1 mail=1 rcpt=0/1 quit=1 commands=3/4
58. Dec 27 06:23:33 m-gate postfix/anvil[29307]: statistics: max connection rate 1/60s for (smtp:193.56.29.119) at Dec 27 06:19:49
59. Dec 27 06:23:33 m-gate postfix/anvil[29307]: statistics: max connection count 1 for (smtp:193.56.29.119) at Dec 27 06:19:49
60. Dec 27 06:23:33 m-gate postfix/anvil[29307]: statistics: max cache size 2 at Dec 27 06:20:11
61. Dec 27 06:23:38 m-gate postfix/smtpd[30590]: connect from unknown[193.56.29.119]
62. Dec 27 06:23:43 m-gate postfix/smtpd[30590]: disconnect from unknown[193.56.29.119] ehlo=1 auth=0/1 rset=1 quit=1 commands=3/4
63. Dec 27 06:24:25 m-gate postfix/smtpd[30590]: connect from mail.begbnhauuyainning.work[77.90.145.4]
64. Dec 27 06:24:26 m-gate postfix/smtpd[30590]: NOQUEUE: reject: RCPT from mail.begbnhauuyainning.work[77.90.145.4]: 554 5.7.1 Service unavailable; Client host [77.90.145.4] blocked using zen.spamhaus.org; from=<va.rate.guide-xxxxxxxxxxxxxxx@begbnhauuyainning.work> to=<xxxxxxxxxxxxxxx> proto=ESMTP helo=<mail.begbnhauuyainning.work>
65. Dec 27 06:24:26 m-gate postfix/smtpd[30590]: NOQUEUE: reject: RCPT from mail.begbnhauuyainning.work[77.90.145.4]: 554 5.7.1 Service unavailable; Client host [77.90.145.4] blocked using zen.spamhaus.org; from=<va_rate_guide-xxxxxxxxxxxxxxx@begbnhauuyainning.work> to=<xxxxxxxxxxxxxxx> proto=ESMTP helo=<mail.begbnhauuyainning.work>
66. Dec 27 06:24:27 m-gate postfix/smtpd[30590]: disconnect from mail.begbnhauuyainning.work[77.90.145.4] ehlo=1 mail=2 rcpt=0/2 rset=1 quit=1 commands=5/7
67. Dec 27 06:27:47 m-gate postfix/anvil[30591]: statistics: max connection rate 1/60s for (smtp:193.56.29.119) at Dec 27 06:23:38
68. Dec 27 06:27:47 m-gate postfix/anvil[30591]: statistics: max connection count 1 for (smtp:193.56.29.119) at Dec 27 06:23:38
69. Dec 27 06:27:47 m-gate postfix/anvil[30591]: statistics: max cache size 2 at Dec 27 06:24:25
70. Dec 27 06:28:26 m-gate postfix/smtpd[31895]: connect from unknown[193.56.29.119]
71. Dec 27 06:28:34 m-gate postfix/smtpd[31895]: disconnect from unknown[193.56.29.119] ehlo=1 auth=0/1 rset=1 quit=1 commands=3/4
72. Dec 27 06:31:59 m-gate postfix/anvil[31896]: statistics: max connection rate 1/60s for (smtp:193.56.29.119) at Dec 27 06:28:26
73. Dec 27 06:31:59 m-gate postfix/anvil[31896]: statistics: max connection count 1 for (smtp:193.56.29.119) at Dec 27 06:28:26
74. Dec 27 06:31:59 m-gate postfix/anvil[31896]: statistics: max cache size 1 at Dec 27 06:28:26
75. Dec 27 06:36:39 m-gate postfix/smtpd[474]: connect from unknown[193.56.29.119]
76. Dec 27 06:37:07 m-gate postfix/smtpd[474]: disconnect from unknown[193.56.29.119] ehlo=1 auth=0/1 rset=1 quit=1 commands=3/4
77. Dec 27 06:40:37 m-gate postfix/anvil[475]: statistics: max connection rate 1/60s for (smtp:193.56.29.119) at Dec 27 06:36:42
78. Dec 27 06:40:37 m-gate postfix/anvil[475]: statistics: max connection count 1 for (smtp:193.56.29.119) at Dec 27 06:36:42
79. Dec 27 06:40:37 m-gate postfix/anvil[475]: statistics: max cache size 1 at Dec 27 06:36:42
80. Dec 27 06:42:57 m-gate postfix/smtpd[1947]: connect from unknown[134.73.36.199]
81. Dec 27 06:43:05 m-gate postfix/smtpd[1947]: NOQUEUE: reject: RCPT from unknown[134.73.36.199]: 554 5.7.1 Service unavailable; Client host [134.73.36.199] blocked using zen.spamhaus.org; https://www.spamhaus.org/sbl/query/SBL538345 / https://www.spamhaus.org/sbl/query/SBLCSS; from=<45473-959-256170-11903-xxxxxxxxxxxxxxx@mail.coolairs.us> to=<xxxxxxxxxxxxxxx> proto=ESMTP helo=<able.coolairs.us>
82. Dec 27 06:43:07 m-gate postfix/smtpd[1947]: NOQUEUE: reject: RCPT from unknown[134.73.36.199]: 554 5.7.1 Service unavailable; Client host [134.73.36.199] blocked using zen.spamhaus.org; https://www.spamhaus.org/sbl/query/SBL538345 / https://www.spamhaus.org/sbl/query/SBLCSS; from=<45473-959-21466-11903-xxxxxxxxxxxxxxx@mail.coolairs.us> to=<xxxxxxxxxxxxxxx> proto=ESMTP helo=<able.coolairs.us>
83. Dec 27 06:43:07 m-gate postfix/smtpd[1947]: disconnect from unknown[134.73.36.199] ehlo=1 mail=2 rcpt=0/2 rset=1 quit=1 commands=5/7
84. Dec 27 06:46:29 m-gate postfix/anvil[1948]: statistics: max connection rate 1/60s for (smtp:134.73.36.199) at Dec 27 06:43:00
85. Dec 27 06:46:29 m-gate postfix/anvil[1948]: statistics: max connection count 1 for (smtp:134.73.36.199) at Dec 27 06:43:00
86. Dec 27 06:46:29 m-gate postfix/anvil[1948]: statistics: max cache size 1 at Dec 27 06:43:00
87. Dec 27 06:47:31 m-gate postfix/smtpd[2639]: connect from unknown[103.170.255.216]
88. Dec 27 06:47:34 m-gate postfix/smtpd[2639]: NOQUEUE: reject: RCPT from unknown[103.170.255.216]: 554 5.7.1 <spameri@tiscali.it>: Relay access denied; from=<spameri@tiscali.it> to=<spameri@tiscali.it> proto=ESMTP helo=<WIN-QZ1C4UHYJ82>
89. Dec 27 06:47:34 m-gate postfix/smtpd[2639]: disconnect from unknown[103.170.255.216] ehlo=1 mail=1 rcpt=0/1 rset=1 quit=1 commands=4/5
90. Dec 27 06:50:54 m-gate postfix/anvil[2640]: statistics: max connection rate 1/60s for (smtp:103.170.255.216) at Dec 27 06:47:31
91. Dec 27 06:50:54 m-gate postfix/anvil[2640]: statistics: max connection count 1 for (smtp:103.170.255.216) at Dec 27 06:47:31
92. Dec 27 06:50:54 m-gate postfix/anvil[2640]: statistics: max cache size 1 at Dec 27 06:47:31
93. Dec 27 06:57:29 m-gate postfix/smtpd[4490]: connect from mail.books24x7.com[170.52.47.41]
94. Dec 27 06:57:30 m-gate postfix/smtpd[4490]: Anonymous TLS connection established from mail.books24x7.com[170.52.47.41]: TLSv1.2 with cipher ECDHE-RSA-AES256-GCM-SHA384 (256/256 bits)
95. Dec 27 06:57:31 m-gate postfix/cleanup[4497]: 4JMvkz1ZY3z9ZF8: message-id=<4JMvkz1ZY3z9ZF8@m-gate. xxxxxxxxxxxxxxx>
96. Dec 27 06:57:31 m-gate postfix/qmgr[2299]: 4JMvkz1ZY3z9ZF8: from=<double-bounce@xxxxxxxxxxxxxxx>, size=292, nrcpt=1 (queue active)
97. Dec 27 06:57:31 m-gate postfix/smtpd[4490]: 4JMvkz2CgMz9ZF9: client=mail.books24x7.com[170.52.47.41]
98. Dec 27 06:57:31 m-gate postfix/cleanup[4497]: 4JMvkz2CgMz9ZF9: message-id=<>
99. Dec 27 06:57:31 m-gate opendkim[2832]: 4JMvkz2CgMz9ZF9: mail.books24x7.com [170.52.47.41] not internal
100. Dec 27 06:57:31 m-gate opendkim[2832]: 4JMvkz2CgMz9ZF9: not authenticated
101. Dec 27 06:57:31 m-gate opendkim[2832]: 4JMvkz2CgMz9ZF9: no signature data
102. Dec 27 06:57:32 m-gate opendmarc[2831]: 4JMvkz2CgMz9ZF9: SPF(mailfrom): b24x7.com none
103. Dec 27 06:57:32 m-gate opendmarc[2831]: 4JMvkz2CgMz9ZF9: b24x7.com none
104. Dec 27 06:57:33 m-gate MSMilter[4494]: MailWatch: Allowlist refresh time reached
105. Dec 27 06:57:33 m-gate MSMilter[4494]: MailWatch: Starting up MailWatch SQL Allowlist
106. Dec 27 06:57:33 m-gate MSMilter[4494]: MailWatch: Read 3 allowlist entries
107. Dec 27 06:57:33 m-gate MSMilter[4494]: MailWatch: Blocklist refresh time reached
108. Dec 27 06:57:33 m-gate MSMilter[4494]: MailWatch: Starting up MailWatch SQL Blocklist
109. Dec 27 06:57:33 m-gate MSMilter[4494]: MailWatch: Read 0 blocklist entries
110. Dec 27 06:57:33 m-gate postfix/cleanup[4497]: 4JMvkz2CgMz9ZF9: milter-discard: END-OF-MESSAGE from mail.books24x7.com[170.52.47.41]: milter triggers DISCARD action; from=<new-titles@b24x7.com> to=<xxxxxxxxxxxxxxx> proto=ESMTP helo=<mail.b24x7.com>
111. Dec 27 06:57:33 m-gate postfix/smtpd[4490]: disconnect from mail.books24x7.com[170.52.47.41] ehlo=2 starttls=1 mail=1 rcpt=1 data=1 quit=1 commands=7
112. Dec 27 06:57:36 m-gate postfix/smtp[4498]: 4JMvkz1ZY3z9ZF8: to=<xxxxxxxxxxxxxxx>, relay=192.168.yyyy.yyyy[192.168.yyyy.yyyy]:25, delay=5.1, delays=0.04/0.05/0.03/5, dsn=2.1.5, status=deliverable (250 2.1.5 Recipient OK)
113. Dec 27 06:57:36 m-gate postfix/qmgr[2299]: 4JMvkz1ZY3z9ZF8: removed
114. Dec 27 06:57:41 m-gate MailScanner[18265]: New Batch: Scanning 1 messages, 140486 bytes
115. Dec 27 06:57:45 m-gate MailScanner[18265]: Virus and Content Scanning: Starting
116. Dec 27 06:58:54 m-gate MailScanner[18265]: <A> tag found in message 4JMvkz2CgMz9ZF9 from new-titles@b24x7.com
117. Dec 27 06:58:54 m-gate MailScanner[18265]: HTML Img tag found in message 4JMvkz2CgMz9ZF9 from new-titles@b24x7.com
118. Dec 27 06:58:54 m-gate MailScanner[18265]: Spam Checks: Starting
119. Dec 27 06:58:54 m-gate MailScanner[18265]: Expired 6 records from the SpamAssassin cache
120. Dec 27 06:58:54 m-gate MailScanner[18265]: MailWatch: Allowlist refresh time reached
121. Dec 27 06:58:54 m-gate MailScanner[18265]: MailWatch: Starting up MailWatch SQL Allowlist
122. Dec 27 06:58:54 m-gate MailScanner[18265]: MailWatch: Read 3 allowlist entries
123. Dec 27 06:58:54 m-gate MailScanner[18265]: MailWatch: Blocklist refresh time reached
124. Dec 27 06:58:54 m-gate MailScanner[18265]: MailWatch: Starting up MailWatch SQL Blocklist
125. Dec 27 06:58:54 m-gate MailScanner[18265]: MailWatch: Read 0 blocklist entries
126. Dec 27 06:59:12 m-gate MailScanner[18265]: Requeue: 4JMvkz2CgMz9ZF9 to 4JMvkz2CgMz9ZF9
127. Dec 27 06:59:12 m-gate postfix/qmqpd[4768]: connect from localhost[127.0.0.1]
128. Dec 27 06:59:12 m-gate postfix/qmqpd[4768]: 4JMvmw2DYvz9ZF8: client=localhost[127.0.0.1]
129. Dec 27 06:59:12 m-gate opendmarc[2831]: ignoring connection from localhost
130. Dec 27 06:59:12 m-gate postfix/cleanup[4497]: 4JMvmw2DYvz9ZF8: message-id=<4JMvmw2DYvz9ZF8@m-gate. xxxxxxxxxxxxxxx>
131. Dec 27 06:59:12 m-gate opendkim[2832]: 4JMvmw2DYvz9ZF8: no signature data
132. Dec 27 06:59:12 m-gate postfix/qmgr[2299]: 4JMvmw2DYvz9ZF8: from=<new-titles@b24x7.com>, size=140925, nrcpt=1 (queue active)
133. Dec 27 06:59:12 m-gate postfix/qmqpd[4768]: disconnect from localhost[127.0.0.1]
134. Dec 27 06:59:12 m-gate MailScanner[18265]: Uninfected: Delivered 1 messages
135. Dec 27 06:59:12 m-gate MailScanner[18265]: MailWatch: Could not extract Message-ID for 4JMvkz2CgMz9ZF9
136. Dec 27 06:59:12 m-gate MailScanner[18265]: MailWatch: Started MailWatch SQL Logging child
137. Dec 27 06:59:12 m-gate postfix/smtp[4498]: 4JMvmw2DYvz9ZF8: to=<xxxxxxxxxxxxxxx>, relay=192.168.yyyy.yyyy[192.168.yyyy.yyyy]:25, delay=0.33, delays=0.05/0/0/0.27, dsn=2.6.0, status=sent (250 2.6.0 <4JMvmw2DYvz9ZF8@m-gate. xxxxxxxxxxxxxxx> Queued mail for delivery)
138. Dec 27 06:59:12 m-gate postfix/qmgr[2299]: 4JMvmw2DYvz9ZF8: removed
139. Dec 27 06:59:17 m-gate MailScanner[18265]: MailWatch: Logging message 4JMvkz2CgMz9ZF9 to SQL
140. Dec 27 06:59:18 m-gate MailScanner[4772]: MailWatch: 4JMvkz2CgMz9ZF9: Logged to MailWatch SQL
141. Dec 27 07:00:54 m-gate postfix/anvil[4491]: statistics: max connection rate 1/60s for (smtp:170.52.47.41) at Dec 27 06:57:29
142. Dec 27 07:00:54 m-gate postfix/anvil[4491]: statistics: max connection count 1 for (smtp:170.52.47.41) at Dec 27 06:57:29
143. Dec 27 07:00:54 m-gate postfix/anvil[4491]: statistics: max cache size 1 at Dec 27 06:57:29
144. Dec 27 07:03:16 m-gate postfix/smtpd[5304]: connect from vmta176.84.lstrk.net[142.0.84.176]
145. Dec 27 07:03:17 m-gate postfix/smtpd[5304]: 4JMvsd1fHhz9ZF8: client=vmta176.84.lstrk.net[142.0.84.176]
146. Dec 27 07:03:17 m-gate postfix/cleanup[5311]: 4JMvsd1fHhz9ZF8: message-id=<0.2.AF.A32.1D7FB1159794462.4C55@vmta176.84.lstrk.net>
147. Dec 27 07:03:17 m-gate opendkim[2832]: 4JMvsd1fHhz9ZF8: vmta176.84.lstrk.net [142.0.84.176] not internal
148. Dec 27 07:03:17 m-gate opendkim[2832]: 4JMvsd1fHhz9ZF8: not authenticated
149. Dec 27 07:03:17 m-gate opendkim[2832]: 4JMvsd1fHhz9ZF8: message has signatures from e-mail.avanquest.com, esp1.co
150. Dec 27 07:03:17 m-gate opendkim[2832]: 4JMvsd1fHhz9ZF8: DKIM verification successful
151. Dec 27 07:03:17 m-gate opendmarc[2831]: 4JMvsd1fHhz9ZF8: SPF(mailfrom): bounce.e-mail.avanquest.com none
152. Dec 27 07:03:17 m-gate opendmarc[2831]: 4JMvsd1fHhz9ZF8: e-mail.avanquest.com pass
153. Dec 27 07:03:18 m-gate MSMilter[5308]: MailWatch: Allowlist refresh time reached
154. Dec 27 07:03:18 m-gate MSMilter[5308]: MailWatch: Starting up MailWatch SQL Allowlist
155. Dec 27 07:03:18 m-gate MSMilter[5308]: MailWatch: Read 3 allowlist entries
156. Dec 27 07:03:18 m-gate MSMilter[5308]: MailWatch: Blocklist refresh time reached
157. Dec 27 07:03:18 m-gate MSMilter[5308]: MailWatch: Starting up MailWatch SQL Blocklist
158. Dec 27 07:03:18 m-gate MSMilter[5308]: MailWatch: Read 0 blocklist entries
159. Dec 27 07:03:18 m-gate postfix/cleanup[5311]: 4JMvsd1fHhz9ZF8: milter-discard: END-OF-MESSAGE from vmta176.84.lstrk.net[142.0.84.176]: milter triggers DISCARD action; from=<PDOR6C3MIC23R7DP3G31MAMDRGO1NAAPMMN6A2T3324@bounce.e-mail.avanquest.com> to=<xxxxxxxxxxxxxxx> proto=ESMTP helo=<vmta176.84.lstrk.net>
160. Dec 27 07:03:18 m-gate postfix/smtpd[5304]: disconnect from vmta176.84.lstrk.net[142.0.84.176] ehlo=1 mail=1 rcpt=1 data=1 quit=1 commands=5
161. Dec 27 07:03:22 m-gate MailScanner[18314]: New Batch: Scanning 1 messages, 21518 bytes
162. Dec 27 07:03:25 m-gate MailScanner[18314]: Virus and Content Scanning: Starting
163. Dec 27 07:03:48 m-gate MailScanner[18314]: <A> tag found in message 4JMvsd1fHhz9ZF8 from pdor6c3mic23r7dp3g31mamdrgo1naapmmn6a2t3324@bounce.e-mail.avanquest.com
164. Dec 27 07:03:48 m-gate MailScanner[18314]: HTML Img tag found in message 4JMvsd1fHhz9ZF8 from pdor6c3mic23r7dp3g31mamdrgo1naapmmn6a2t3324@bounce.e-mail.avanquest.com
165. Dec 27 07:03:48 m-gate MailScanner[18314]: Spam Checks: Starting
166. Dec 27 07:03:48 m-gate MailScanner[18314]: MailWatch: Allowlist refresh time reached
167. Dec 27 07:03:48 m-gate MailScanner[18314]: MailWatch: Starting up MailWatch SQL Allowlist
168. Dec 27 07:03:48 m-gate MailScanner[18314]: MailWatch: Read 3 allowlist entries
169. Dec 27 07:03:48 m-gate MailScanner[18314]: MailWatch: Blocklist refresh time reached
170. Dec 27 07:03:48 m-gate MailScanner[18314]: MailWatch: Starting up MailWatch SQL Blocklist
171. Dec 27 07:03:48 m-gate MailScanner[18314]: MailWatch: Read 0 blocklist entries
172. Dec 27 07:03:54 m-gate MailScanner[18314]: Requeue: 4JMvsd1fHhz9ZF8 to 4JMvsd1fHhz9ZF8
173. Dec 27 07:03:54 m-gate postfix/qmqpd[5328]: connect from localhost[127.0.0.1]
174. Dec 27 07:03:54 m-gate postfix/qmqpd[5328]: 4JMvtL3hT0z9ZF8: client=localhost[127.0.0.1]
175. Dec 27 07:03:54 m-gate opendmarc[2831]: ignoring connection from localhost
176. Dec 27 07:03:54 m-gate postfix/cleanup[5311]: 4JMvtL3hT0z9ZF8: message-id=<0.2.AF.A32.1D7FB1159794462.4C55@vmta176.84.lstrk.net>
177. Dec 27 07:03:54 m-gate opendkim[2832]: 4JMvtL3hT0z9ZF8: message has signatures from e-mail.avanquest.com, esp1.co
178. Dec 27 07:03:54 m-gate opendkim[2832]: 4JMvtL3hT0z9ZF8: DKIM verification successful
179. Dec 27 07:03:54 m-gate postfix/qmgr[2299]: 4JMvtL3hT0z9ZF8: from=<pdor6c3mic23r7dp3g31mamdrgo1naapmmn6a2t3324@bounce.e-mail.avanquest.com>, size=22015, nrcpt=1 (queue active)
180. Dec 27 07:03:54 m-gate postfix/qmqpd[5328]: disconnect from localhost[127.0.0.1]
181. Dec 27 07:03:54 m-gate MailScanner[18314]: Uninfected: Delivered 1 messages
182. Dec 27 07:03:54 m-gate MailScanner[18314]: MailWatch: Logging message 4JMvsd1fHhz9ZF8 to SQL
183. Dec 27 07:03:54 m-gate MailScanner[4772]: MailWatch: 4JMvsd1fHhz9ZF8: Logged to MailWatch SQL
184. Dec 27 07:03:54 m-gate postfix/smtp[5331]: 4JMvtL3hT0z9ZF8: to=<xxxxxxxxxxxxxxx>, relay=192.168.yyyy.yyyy[192.168.yyyy.yyyy]:25, delay=0.2, delays=0.06/0.02/0.01/0.11, dsn=2.6.0, status=sent (250 2.6.0 <0.2.AF.A32.1D7FB1159794462.4C55@vmta176.84.lstrk.net> Queued mail for delivery)
185. Dec 27 07:03:54 m-gate postfix/qmgr[2299]: 4JMvtL3hT0z9ZF8: removed
186. Dec 27 07:06:38 m-gate postfix/anvil[5305]: statistics: max connection rate 1/60s for (smtp:142.0.84.176) at Dec 27 07:03:16
187. Dec 27 07:06:38 m-gate postfix/anvil[5305]: statistics: max connection count 1 for (smtp:142.0.84.176) at Dec 27 07:03:16
188. Dec 27 07:06:38 m-gate postfix/anvil[5305]: statistics: max cache size 1 at Dec 27 07:03:16
189. Dec 27 07:15:24 m-gate postfix/smtpd[6926]: connect from unknown[111.23.117.97]
190. Dec 27 07:15:27 m-gate postfix/smtpd[6926]: NOQUEUE: reject: RCPT from unknown[111.23.117.97]: 554 5.7.1 Service unavailable; Client host [111.23.117.97] blocked using zen.spamhaus.org; https://www.spamhaus.org/query/ip/111.23.117.97; from=<vpixoalqwi@mega.nz> to=<xxxxxxxxxxxxxxx> proto=ESMTP helo=<mega.nz>
191. Dec 27 07:15:27 m-gate postfix/smtpd[6926]: NOQUEUE: reject: RCPT from unknown[111.23.117.97]: 554 5.7.1 Service unavailable; Client host [111.23.117.97] blocked using zen.spamhaus.org; https://www.spamhaus.org/query/ip/111.23.117.97; from=<vpixoalqwi@mega.nz> to=<xxxxxxxxxxxxxxx> proto=ESMTP helo=<mega.nz>
192. Dec 27 07:15:28 m-gate postfix/smtpd[6926]: disconnect from unknown[111.23.117.97] ehlo=1 mail=1 rcpt=0/2 quit=1 commands=3/5
193. Dec 27 07:18:49 m-gate postfix/anvil[6927]: statistics: max connection rate 1/60s for (smtp:111.23.117.97) at Dec 27 07:15:24
194. Dec 27 07:18:49 m-gate postfix/anvil[6927]: statistics: max connection count 1 for (smtp:111.23.117.97) at Dec 27 07:15:24
195. Dec 27 07:18:49 m-gate postfix/anvil[6927]: statistics: max cache size 1 at Dec 27 07:15:24
196. Dec 27 07:19:41 m-gate postfix/smtpd[7441]: connect from mail.veriomta.com[104.216.54.224]
197. Dec 27 07:19:42 m-gate postfix/smtpd[7441]: NOQUEUE: reject: RCPT from mail.veriomta.com[104.216.54.224]: 554 5.7.1 Service unavailable; Client host [104.216.54.224] blocked using zen.spamhaus.org; https://www.spamhaus.org/sbl/query/SBLCSS; from=<striction-blood-pressure-xxxxxxxxxxxxxxx@xdvhe.com> to=<xxxxxxxxxxxxxxx proto=ESMTP helo=<mail.xdvhe.com>
198. Dec 27 07:19:43 m-gate postfix/smtpd[7441]: disconnect from mail.veriomta.com[104.216.54.224] ehlo=1 mail=1 rcpt=0/1 quit=1 commands=3/4
199. Dec 27 07:23:03 m-gate postfix/anvil[7442]: statistics: max connection rate 1/60s for (smtp:104.216.54.224) at Dec 27 07:19:41
200. Dec 27 07:23:03 m-gate postfix/anvil[7442]: statistics: max connection count 1 for (smtp:104.216.54.224) at Dec 27 07:19:41
201. Dec 27 07:23:03 m-gate postfix/anvil[7442]: statistics: max cache size 1 at Dec 27 07:19:41
202. Dec 27 07:47:27 m-gate postfix/smtpd[11970]: connect from mail.imbnhuyapact.cam[77.90.138.102]
203. Dec 27 07:47:28 m-gate postfix/smtpd[11970]: 4JMwrc4Vljz9ZF8: client=mail.imbnhuyapact.cam[77.90.138.102]
204. Dec 27 07:47:28 m-gate postfix/cleanup[11977]: 4JMwrc4Vljz9ZF8: message-id=<0.0.0.3.1D7FB16EE9E19F0.130E99@mail.imbnhuyapact.cam>
205. Dec 27 07:47:28 m-gate opendkim[2832]: 4JMwrc4Vljz9ZF8: mail.imbnhuyapact.cam [77.90.138.102] not internal
206. Dec 27 07:47:28 m-gate opendkim[2832]: 4JMwrc4Vljz9ZF8: not authenticated
207. Dec 27 07:47:29 m-gate opendkim[2832]: 4JMwrc4Vljz9ZF8: DKIM verification successful
208. Dec 27 07:47:29 m-gate opendmarc[2831]: 4JMwrc4Vljz9ZF8: SPF(mailfrom): imbnhuyapact.cam pass
209. Dec 27 07:47:29 m-gate opendmarc[2831]: 4JMwrc4Vljz9ZF8: imbnhuyapact.cam pass
210. Dec 27 07:47:30 m-gate MSMilter[11974]: MailWatch: Allowlist refresh time reached
211. Dec 27 07:47:30 m-gate MSMilter[11974]: MailWatch: Starting up MailWatch SQL Allowlist
212. Dec 27 07:47:30 m-gate MSMilter[11974]: MailWatch: Read 3 allowlist entries
213. Dec 27 07:47:30 m-gate MSMilter[11974]: MailWatch: Blocklist refresh time reached
214. Dec 27 07:47:30 m-gate MSMilter[11974]: MailWatch: Starting up MailWatch SQL Blocklist
215. Dec 27 07:47:30 m-gate MSMilter[11974]: MailWatch: Read 0 blocklist entries
216. Dec 27 07:47:30 m-gate postfix/cleanup[11977]: 4JMwrc4Vljz9ZF8: milter-discard: END-OF-MESSAGE from mail.imbnhuyapact.cam[77.90.138.102]: milter triggers DISCARD action; from=<age.defying-xxxxxxxxxxxxxxx@imbnhuyapact.cam> to=<xxxxxxxxxxxxxxx> proto=ESMTP helo=<mail.imbnhuyapact.cam>
217. Dec 27 07:47:30 m-gate postfix/smtpd[11970]: 4JMwrf3x2Wz9ZF8: client=mail.imbnhuyapact.cam[77.90.138.102]
218. Dec 27 07:47:30 m-gate MailScanner[18314]: New Batch: Scanning 1 messages, 7451 bytes
219. Dec 27 07:47:30 m-gate postfix/cleanup[11977]: 4JMwrf3x2Wz9ZF8: message-id=<0.0.0.3.1D7FB16EE9E19F0.13949E@mail.imbnhuyapact.cam>
220. Dec 27 07:47:30 m-gate MailScanner[18314]: Virus and Content Scanning: Starting
221. Dec 27 07:47:30 m-gate opendkim[2832]: 4JMwrf3x2Wz9ZF8: mail.imbnhuyapact.cam [77.90.138.102] not internal
222. Dec 27 07:47:30 m-gate opendkim[2832]: 4JMwrf3x2Wz9ZF8: not authenticated
223. Dec 27 07:47:30 m-gate opendkim[2832]: 4JMwrf3x2Wz9ZF8: DKIM verification successful
224. Dec 27 07:47:30 m-gate opendmarc[2831]: 4JMwrf3x2Wz9ZF8: SPF(mailfrom): imbnhuyapact.cam pass
225. Dec 27 07:47:30 m-gate opendmarc[2831]: 4JMwrf3x2Wz9ZF8: imbnhuyapact.cam pass
226. Dec 27 07:47:31 m-gate postfix/cleanup[11977]: 4JMwrf3x2Wz9ZF8: milter-discard: END-OF-MESSAGE from mail.imbnhuyapact.cam[77.90.138.102]: milter triggers DISCARD action; from=<age_defying-xxxxxxxxxxxxxxx@imbnhuyapact.cam> to=<xxxxxxxxxxxxxxx> proto=ESMTP helo=<mail.imbnhuyapact.cam>
227. Dec 27 07:47:31 m-gate postfix/smtpd[11970]: disconnect from mail.imbnhuyapact.cam[77.90.138.102] ehlo=1 mail=2 rcpt=2 bdat=2 quit=1 commands=8
228. Dec 27 07:47:32 m-gate MailScanner[18314]: <A> tag found in message 4JMwrc4Vljz9ZF8 from age.defying-xxxxxxxxxxxxxxx@imbnhuyapact.cam
229. Dec 27 07:47:32 m-gate MailScanner[18314]: HTML Img tag found in message 4JMwrc4Vljz9ZF8 from age.defying-xxxxxxxxxxxxxxx@imbnhuyapact.cam
230. Dec 27 07:47:32 m-gate MailScanner[18314]: Spam Checks: Starting
231. Dec 27 07:47:32 m-gate MailScanner[18314]: Expired 2 records from the SpamAssassin cache
232. Dec 27 07:47:32 m-gate MailScanner[18314]: MailWatch: Allowlist refresh time reached
233. Dec 27 07:47:32 m-gate MailScanner[18314]: MailWatch: Starting up MailWatch SQL Allowlist
234. Dec 27 07:47:32 m-gate MailScanner[18314]: MailWatch: Read 3 allowlist entries
235. Dec 27 07:47:32 m-gate MailScanner[18314]: MailWatch: Blocklist refresh time reached
236. Dec 27 07:47:32 m-gate MailScanner[18314]: MailWatch: Starting up MailWatch SQL Blocklist
237. Dec 27 07:47:32 m-gate MailScanner[18314]: MailWatch: Read 0 blocklist entries
238. Dec 27 07:47:37 m-gate MailScanner[18322]: New Batch: Found 2 messages waiting
239. Dec 27 07:47:37 m-gate MailScanner[18322]: New Batch: Scanning 1 messages, 7623 bytes
240. Dec 27 07:47:39 m-gate MailScanner[18314]: Requeue: 4JMwrc4Vljz9ZF8 to 4JMwrc4Vljz9ZF8
241. Dec 27 07:47:39 m-gate postfix/qmqpd[11995]: connect from localhost[127.0.0.1]
242. Dec 27 07:47:39 m-gate postfix/qmqpd[11995]: 4JMwrq3Zwjz9ZF8: client=localhost[127.0.0.1]
243. Dec 27 07:47:39 m-gate opendmarc[2831]: ignoring connection from localhost
244. Dec 27 07:47:39 m-gate postfix/cleanup[11977]: 4JMwrq3Zwjz9ZF8: message-id=<0.0.0.3.1D7FB16EE9E19F0.130E99@mail.imbnhuyapact.cam>
245. Dec 27 07:47:39 m-gate opendkim[2832]: 4JMwrq3Zwjz9ZF8: DKIM verification successful
246. Dec 27 07:47:39 m-gate postfix/qmgr[2299]: 4JMwrq3Zwjz9ZF8: from=<age.defying-xxxxxxxxxxxxxxx@imbnhuyapact.cam>, size=7915, nrcpt=1 (queue active)
247. Dec 27 07:47:39 m-gate postfix/qmqpd[11995]: disconnect from localhost[127.0.0.1]
248. Dec 27 07:47:39 m-gate MailScanner[18314]: Uninfected: Delivered 1 messages
249. Dec 27 07:47:39 m-gate MailScanner[18314]: MailWatch: Logging message 4JMwrc4Vljz9ZF8 to SQL
250. Dec 27 07:47:39 m-gate MailScanner[18314]: Config: calling custom end function SQLBlacklist
251. Dec 27 07:47:39 m-gate MailScanner[18314]: MailWatch: Closing down MailWatch SQL Blocklist
252. Dec 27 07:47:39 m-gate MailScanner[18314]: Config: calling custom end function MailWatchLogging
253. Dec 27 07:47:39 m-gate MailScanner[18314]: Config: calling custom end function SQLWhitelist
254. Dec 27 07:47:39 m-gate MailScanner[18314]: MailWatch: Closing down MailWatch SQL Allowlist
255. Dec 27 07:47:39 m-gate MailScanner[18314]: MailScanner child dying of old age
256. Dec 27 07:47:39 m-gate MailScanner[4772]: MailWatch: 4JMwrc4Vljz9ZF8: Logged to MailWatch SQL
257. Dec 27 07:47:39 m-gate postfix/smtp[11998]: 4JMwrq3Zwjz9ZF8: to=<xxxxxxxxxxxxxxx>, relay=192.168.yyyy.yyyy[192.168.yyyy.yyyy]:25, delay=0.29, delays=0.05/0.02/0.06/0.15, dsn=2.6.0, status=sent (250 2.6.0 <0.0.0.3.1D7FB16EE9E19F0.130E99@mail.imbnhuyapact.cam> Queued mail for delivery)
258. Dec 27 07:47:39 m-gate postfix/qmgr[2299]: 4JMwrq3Zwjz9ZF8: removed
259. Dec 27 07:47:41 m-gate MailScanner[11999]: MailScanner Email Processor version 5.4.2 starting...
260. Dec 27 07:47:45 m-gate MailScanner[18322]: Virus and Content Scanning: Starting
261. Dec 27 07:47:46 m-gate MailScanner[11999]: Reading configuration file /etc/MailScanner/MailScanner.conf
262. Dec 27 07:47:51 m-gate MailScanner[11999]: Reading configuration file /etc/MailScanner/conf.d/README
263. Dec 27 07:47:51 m-gate MailScanner[11999]: Read 1500 hostnames from the phishing whitelist
264. Dec 27 07:47:51 m-gate MailScanner[11999]: Read 4303 hostnames from the phishing blacklists
265. Dec 27 07:47:51 m-gate MailScanner[11999]: Config: calling custom init function SQLBlacklist
266. Dec 27 07:47:51 m-gate MailScanner[11999]: MailWatch: Starting up MailWatch SQL Blocklist
267. Dec 27 07:47:52 m-gate MailScanner[11999]: MailWatch: Read 0 blocklist entries
268. Dec 27 07:47:52 m-gate MailScanner[11999]: Config: calling custom init function MailWatchLogging
269. Dec 27 07:47:53 m-gate MailScanner[11999]: MailWatch: Started MailWatch SQL Logging child
270. Dec 27 07:47:53 m-gate MailScanner[11999]: Config: calling custom init function SQLWhitelist
271. Dec 27 07:47:53 m-gate MailScanner[11999]: MailWatch: Starting up MailWatch SQL Allowlist
272. Dec 27 07:47:53 m-gate MailScanner[11999]: MailWatch: Read 3 allowlist entries
273. Dec 27 07:47:55 m-gate MailScanner[11999]: Using SpamAssassin results cache
274. Dec 27 07:47:55 m-gate MailScanner[11999]: Connected to SpamAssassin cache database
275. Dec 27 07:47:55 m-gate MailScanner[11999]: Enabling SpamAssassin auto-whitelist functionality...
276. Dec 27 07:48:01 m-gate MailScanner[11999]: Using locktype = flock
277. Dec 27 07:48:17 m-gate MailScanner[18322]: <A> tag found in message 4JMwrf3x2Wz9ZF8 from age_defying-xxxxxxxxxxxxxxx@imbnhuyapact.cam
278. Dec 27 07:48:17 m-gate MailScanner[18322]: HTML Img tag found in message 4JMwrf3x2Wz9ZF8 from age_defying-xxxxxxxxxxxxxxx@imbnhuyapact.cam
279. Dec 27 07:48:17 m-gate MailScanner[18322]: Spam Checks: Starting
280. Dec 27 07:48:17 m-gate MailScanner[18322]: MailWatch: Allowlist refresh time reached
281. Dec 27 07:48:17 m-gate MailScanner[18322]: MailWatch: Starting up MailWatch SQL Allowlist
282. Dec 27 07:48:17 m-gate MailScanner[18322]: MailWatch: Read 3 allowlist entries
283. Dec 27 07:48:17 m-gate MailScanner[18322]: MailWatch: Blocklist refresh time reached
284. Dec 27 07:48:17 m-gate MailScanner[18322]: MailWatch: Starting up MailWatch SQL Blocklist
285. Dec 27 07:48:17 m-gate MailScanner[18322]: MailWatch: Read 0 blocklist entries
286. Dec 27 07:48:28 m-gate MailScanner[18322]: Requeue: 4JMwrf3x2Wz9ZF8 to 4JMwrf3x2Wz9ZF8
287. Dec 27 07:48:28 m-gate postfix/qmqpd[11995]: connect from localhost[127.0.0.1]
288. Dec 27 07:48:28 m-gate postfix/qmqpd[11995]: 4JMwsm647xz9ZF8: client=localhost[127.0.0.1]
289. Dec 27 07:48:28 m-gate opendmarc[2831]: ignoring connection from localhost
290. Dec 27 07:48:28 m-gate postfix/cleanup[11977]: 4JMwsm647xz9ZF8: message-id=<0.0.0.3.1D7FB16EE9E19F0.13949E@mail.imbnhuyapact.cam>
291. Dec 27 07:48:28 m-gate opendkim[2832]: 4JMwsm647xz9ZF8: DKIM verification successful
292. Dec 27 07:48:28 m-gate postfix/qmgr[2299]: 4JMwsm647xz9ZF8: from=<age_defying-xxxxxxxxxxxxxxx@imbnhuyapact.cam>, size=8078, nrcpt=1 (queue active)
293. Dec 27 07:48:28 m-gate postfix/qmqpd[11995]: disconnect from localhost[127.0.0.1]
294. Dec 27 07:48:28 m-gate MailScanner[18322]: Uninfected: Delivered 1 messages
295. Dec 27 07:48:28 m-gate MailScanner[18322]: MailWatch: Logging message 4JMwrf3x2Wz9ZF8 to SQL
296. Dec 27 07:48:28 m-gate MailScanner[18322]: Config: calling custom end function SQLBlacklist
297. Dec 27 07:48:28 m-gate MailScanner[18322]: MailWatch: Closing down MailWatch SQL Blocklist
298. Dec 27 07:48:28 m-gate MailScanner[18322]: Config: calling custom end function MailWatchLogging
299. Dec 27 07:48:29 m-gate MailScanner[18322]: Config: calling custom end function SQLWhitelist
300. Dec 27 07:48:29 m-gate MailScanner[18322]: MailWatch: Closing down MailWatch SQL Allowlist
301. Dec 27 07:48:29 m-gate MailScanner[18322]: MailScanner child dying of old age
302. Dec 27 07:48:29 m-gate postfix/smtp[11998]: 4JMwsm647xz9ZF8: to=<xxxxxxxxxxxxxxx>, relay=192.168.yyyy.yyyy [192.168.yyyy.yyyy]:25, delay=0.17, delays=0.06/0/0/0.1, dsn=2.6.0, status=sent (250 2.6.0 <0.0.0.3.1D7FB16EE9E19F0.13949E@mail.imbnhuyapact.cam> Queued mail for delivery)
303. Dec 27 07:48:29 m-gate postfix/qmgr[2299]: 4JMwsm647xz9ZF8: removed
304. Dec 27 07:48:29 m-gate MailScanner[12008]: MailWatch: 4JMwrf3x2Wz9ZF8: Logged to MailWatch SQL
305. Dec 27 07:48:29 m-gate MailScanner[12146]: MailScanner Email Processor version 5.4.2 starting...
306. Dec 27 07:48:29 m-gate MailScanner[12146]: Reading configuration file /etc/MailScanner/MailScanner.conf
307. Dec 27 07:48:29 m-gate MailScanner[12146]: Reading configuration file /etc/MailScanner/conf.d/README
308. Dec 27 07:48:29 m-gate MailScanner[12146]: Read 1500 hostnames from the phishing whitelist
309. Dec 27 07:48:29 m-gate MailScanner[12146]: Read 4303 hostnames from the phishing blacklists
310. Dec 27 07:48:29 m-gate MailScanner[12146]: Config: calling custom init function SQLBlacklist
311. Dec 27 07:48:29 m-gate MailScanner[12146]: MailWatch: Starting up MailWatch SQL Blocklist
312. Dec 27 07:48:29 m-gate MailScanner[12146]: MailWatch: Read 0 blocklist entries
313. Dec 27 07:48:29 m-gate MailScanner[12146]: Config: calling custom init function MailWatchLogging
314. Dec 27 07:48:29 m-gate MailScanner[12146]: MailWatch: Started MailWatch SQL Logging child
315. Dec 27 07:48:29 m-gate MailScanner[12146]: Config: calling custom init function SQLWhitelist
316. Dec 27 07:48:29 m-gate MailScanner[12146]: MailWatch: Starting up MailWatch SQL Allowlist
317. Dec 27 07:48:29 m-gate MailScanner[12146]: MailWatch: Read 3 allowlist entries
318. Dec 27 07:48:29 m-gate MailScanner[12146]: Using SpamAssassin results cache
319. Dec 27 07:48:29 m-gate MailScanner[12146]: Connected to SpamAssassin cache database
320. Dec 27 07:48:29 m-gate MailScanner[12146]: Enabling SpamAssassin auto-whitelist functionality...
321. Dec 27 07:48:32 m-gate MailScanner[12146]: Using locktype = flock
322. Dec 27 07:50:52 m-gate postfix/anvil[11971]: statistics: max connection rate 1/60s for (smtp:77.90.138.102) at Dec 27 07:47:27
323. Dec 27 07:50:52 m-gate postfix/anvil[11971]: statistics: max connection count 1 for (smtp:77.90.138.102) at Dec 27 07:47:27
324. Dec 27 07:50:52 m-gate postfix/anvil[11971]: statistics: max cache size 1 at Dec 27 07:47:27

*** End of logfile ***

With reference to the my original query, here is what I have been able to deduce from my review of the log file:

1. Lines 1-48: mail from 5.181.161.112 (classified as SPAM by eFa)
2. Lines 49-54: two attempts to deliver mail from 193.56.29.119 which appear to fail because of "auth=0"
3. Lines 55-60: mail from 104.216.54.230 blocked by zen.spamhaus.org (correctly ignored by eFa)
4. Lines 61-62: one attempt to deliver mail from 193.56.29.119 which appears to fail because of "auth=0"
5. Lines 63-66: mail from 77.90.145.4 blocked by zen.spamhaus.org (correctly ignored by eFa)
6. Lines 67-79: two attempts to deliver mail from 193.56.29.119 which appear to fail because of "auth=0"
7. Lines 80-86: mail from 134.73.36.199 blocked by zen.spamhaus.org (correctly ignored by eFa)
8. Lines 87-92: attempt to relay mail from 103.170.255.216 (correctly ignored by eFa)
9. Lines 93-143: mail from 170.52.47.41(not SPAM; correctly processed by eFa)
10. Lines 144-188: mail from 142.0.84.176 (not SPAM; correctly processed by eFa)
11. Lines 189-195: mail from 111.23.117.97 blocked by zen.spamhaus.org (correctly ignored by eFa)
12. Lines 196-201: mail from 104.216.54.224 blocked by zen.spamhaus.org (correctly ignored by eFa)
13. Lines 202-324: mail from 77.90.138.102 (classified as SPAM by eFa)

If this is indeed the issue, I don't know how to resolve this issue. Is there a feature or setting that I need to turn on in eFa to allow this message to be processed?

Thank you for your support.

Kind regards,

Dale

Re: EFA not processing all mail

Posted: 06 Jan 2022 13:46
by shawniverson
49. Dec 27 06:02:51 m-gate postfix/smtpd[27075]: disconnect from unknown[193.56.29.119] ehlo=1 auth=0/1 rset=1 quit=1 commands=3/4
This isn't an auth issue, that is normal. This is a premature disconnect or interruption of the connection.