EFA not processing all mail

General eFa discussion
Post Reply
francity
Posts: 3
Joined: 27 Dec 2021 17:36

EFA not processing all mail

Post 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 2231 times
mail-redacted.png
mail-redacted.png (16.83 KiB) Viewed 2231 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
User avatar
shawniverson
Posts: 3644
Joined: 13 Jan 2014 23:30
Location: Indianapolis, Indiana USA
Contact:

Re: EFA not processing all mail

Post 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?
francity
Posts: 3
Joined: 27 Dec 2021 17:36

Re: EFA not processing all mail

Post 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
User avatar
shawniverson
Posts: 3644
Joined: 13 Jan 2014 23:30
Location: Indianapolis, Indiana USA
Contact:

Re: EFA not processing all mail

Post 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.
Post Reply