MailScanner 5.1.2 not working

Shawn Iverson iversons at rushville.k12.in.us
Thu Oct 25 11:23:35 UTC 2018 

One issue I spotted is you have the MSMail Queue Type set to long, but it
appears that postfix is using short queue ids.

On Thu, Oct 25, 2018 at 7:19 AM Shawn Iverson <iversons at rushville.k12.in.us>
wrote:

> Koby,
>
> Yes, that is correct, as it should.  Did you run /usr/sbin/MailScanner
> with Debug = yes ?
>
>
>
> On Thu, Oct 25, 2018 at 7:06 AM Koby Peleg Hen <koby at mksoft.co.il> wrote:
>
>> It seem that it always
>>
>> do : milter triggers DISCARD
>>
>>
>> Oct 25 14:03:32 lab postfix/cleanup[23487]: E4206419CC: milter-discard:
>> END-OF-MESSAGE from mail.mksoft.co.il[199.203.52.126]: milter triggers
>> DISCARD a
>> ction; from=<koby at mksoft.co.il> <koby at mksoft.co.il> to=
>> <admin at ofc.mksoft.co.il> <admin at ofc.mksoft.co.il> proto=ESMTP helo=<
>> mail.mksoft.co.il>
>> Oct 25 14:03:32 lab postfix/smtpd[23484]: disconnect from
>> mail.mksoft.co.il[199.203.52.126] ehlo=1 mail=1 rcpt=1 data=1 quit=1
>> commands=5
>>
>> Here is the full log
>>
>> Oct 25 14:03:31 lab MSMilter[23469]: connect_callback: ip = 199.203.52.126
>> Oct 25 14:03:31 lab MSMilter[23469]: helo_callback: Received: from
>> mail.mksoft.co.il
>> Oct 25 14:03:31 lab MSMilter[23469]: msmailqueuetype = long
>> Oct 25 14:03:31 lab MSMilter[23469]: envrcpt_callback: no client
>> certificate requested
>> Oct 25 14:03:31 lab MSMilter[23469]: envrcpt_callback: id =
>> 42gkkq6cnMz750Q datestring = Thu, 25 Oct 2018 14:03:31 +0300 (IDT)
>> Oct 25 14:03:31 lab postfix/smtpd[23484]: E4206419CC: client=
>> mail.mksoft.co.il[199.203.52.126]
>> Oct 25 14:03:31 lab postfix/cleanup[23487]: E4206419CC: message-id=
>> <d0577bf9-22b8-f8ea-2525-16ca68a7b62e at mksoft.co.il>
>> <d0577bf9-22b8-f8ea-2525-16ca68a7b62e at mksoft.co.il>
>> Oct 25 14:03:32 lab MSMilter[23469]: eom_callback: scannermode = yes
>> Oct 25 14:03:32 lab MSMilter[23469]: eoh_callback: to =
>> admin at ofc.mksoft.co.il
>> Oct 25 14:03:32 lab MSMilter[23469]: eoh_callback: ip = 199.203.52.126
>> Oct 25 14:03:32 lab MSMilter[23469]: eoh_callback: id = 42gkkq6cnMz750Q
>> Oct 25 14:03:32 lab MSMilter[23469]: eoh_callback: incoming =
>> /var/spool/MailScanner/milterin
>> Oct 25 14:03:32 lab MSMilter[23469]: eoh_callback: file =
>> /var/spool/MailScanner/milterin/temp-42gkkq6cnMz750Q
>> Oct 25 14:03:32 lab MSMilter[23469]: Not locking spool file
>> >>/var/spool/MailScanner/milterin/temp-42gkkq6cnMz750Q
>> Oct 25 14:03:32 lab MSMilter[23469]: eom_callback: scanner mode enabled
>> Oct 25 14:03:32 lab MSMilter[23469]: eom_callback: no whitelist match,
>> proceeding to blacklist test
>> Oct 25 14:03:32 lab MSMilter[23469]: eoh_callback: End of Header detected
>> Oct 25 14:03:32 lab MSMilter[23469]: body_callback: incoming =
>> /var/spool/MailScanner/milterin
>> Oct 25 14:03:32 lab MSMilter[23469]: body_callback: file =
>> /var/spool/MailScanner/milterin/temp-42gkkq6cnMz750Q
>> Oct 25 14:03:32 lab MSMilter[23469]: Not locking spool file
>> >>/var/spool/MailScanner/milterin/temp-42gkkq6cnMz750Q
>> Oct 25 14:03:32 lab MSMilter[23469]: eom_callback: incoming =
>> /var/spool/MailScanner/milterin
>> Oct 25 14:03:32 lab postfix/cleanup[23487]: E4206419CC: *milter-discard:
>> END-OF-MESSAGE from mail.mksoft.co.il
>> <http://mail.mksoft.co.il>[199.203.52.126]: milter triggers DISCARD *a
>> ction; from=<koby at mksoft.co.il> <koby at mksoft.co.il> to=
>> <admin at ofc.mksoft.co.il> <admin at ofc.mksoft.co.il> proto=ESMTP helo=<
>> mail.mksoft.co.il>
>> Oct 25 14:03:32 lab postfix/smtpd[23484]: disconnect from
>> mail.mksoft.co.il[199.203.52.126] ehlo=1 mail=1 rcpt=1 data=1 quit=1
>> commands=5
>>
>>
>>
>>
>>
>> Hello Koby,
>>
>> It looks like the milter is functioning fine.  We need to focus on
>> MailScanner itself.  The next step would be for MailScanner to pick up the
>> messages and scan them.
>>
>> With Debug on, what do you see in the log when your run
>> "/usr/sbin/MailScanner" one time?
>>
>>
>>
>> On Thu, Oct 25, 2018 at 4:46 AM Koby Peleg Hen <koby at mksoft.co.il> wrote:
>>
>>> I fix all permission on /Mailscanner  > chown -R  postfix:mtagroup
>>>
>>>
>>> But ,
>>>
>>> It is seems that all the mail stuck in the
>>> /var/spool/mailscanner/milterin
>>>
>>> They are not send out to target...
>>>
>>>
>>> here is the log from debug
>>>
>>>
>>> Oct 25 11:40:28 lab postfix/smtpd[10203]: connect from mail.mksoft.co.il
>>> [199.203.52.126]
>>> Oct 25 11:40:28 lab MSMilter[9849]: connect_callback: ip = 199.203.52.126
>>> Oct 25 11:40:28 lab MSMilter[9849]: helo_callback: Received: from
>>> mail.mksoft.co.il
>>> Oct 25 11:40:28 lab MSMilter[9849]: msmailqueuetype = long
>>> Oct 25 11:40:28 lab MSMilter[9849]: envrcpt_callback: no client
>>> certificate requested
>>> Oct 25 11:40:28 lab MSMilter[9849]: envrcpt_callback: id =
>>> 42ggYm3nHjz4TLC datestring = Thu, 25 Oct 2018 11:40:28 +0300 (IDT)
>>> Oct 25 11:40:28 lab postfix/smtpd[10203]: 841DE40068: client=
>>> mail.mksoft.co.il[199.203.52.126]
>>> Oct 25 11:40:28 lab postfix/cleanup[10206]: 841DE40068: message-id=
>>> <0f84b726-ba58-998c-175e-73f5763034f6 at mksoft.co.il>
>>> <0f84b726-ba58-998c-175e-73f5763034f6 at mksoft.co.il>
>>> Oct 25 11:40:29 lab MSMilter[9849]: eom_callback: scannermode = yes
>>> Oct 25 11:40:29 lab MSMilter[9849]: eoh_callback: to =
>>> admin at ofc.mksoft.co.il
>>> Oct 25 11:40:29 lab MSMilter[9849]: eoh_callback: ip = 199.203.52.126
>>> Oct 25 11:40:29 lab MSMilter[9849]: eoh_callback: id = 42ggYm3nHjz4TLC
>>> Oct 25 11:40:29 lab MSMilter[9849]: eoh_callback: incoming =
>>> /var/spool/MailScanner/milterin
>>> Oct 25 11:40:29 lab MSMilter[9849]: eoh_callback: file =
>>> /var/spool/MailScanner/milterin/temp-42ggYm3nHjz4TLC
>>> Oct 25 11:40:29 lab MSMilter[9849]: Not locking spool file
>>> >>/var/spool/MailScanner/milterin/temp-42ggYm3nHjz4TLC
>>> Oct 25 11:40:29 lab MSMilter[9849]: eom_callback: scanner mode enabled
>>> Oct 25 11:40:29 lab MSMilter[9849]: eom_callback: no whitelist match,
>>> proceeding to blacklist test
>>> Oct 25 11:40:29 lab MSMilter[9849]: eoh_callback: End of Header detected
>>> Oct 25 11:40:29 lab MSMilter[9849]: body_callback: incoming =
>>> /var/spool/MailScanner/milterin
>>> Oct 25 11:40:29 lab MSMilter[9849]: body_callback: file =
>>> /var/spool/MailScanner/milterin/temp-42ggYm3nHjz4TLC
>>> Oct 25 11:40:29 lab MSMilter[9849]: Not locking spool file
>>> >>/var/spool/MailScanner/milterin/temp-42ggYm3nHjz4TLC
>>> Oct 25 11:40:29 lab MSMilter[9849]: eom_callback: incoming =
>>> /var/spool/MailScanner/milterin
>>> Oct 25 11:40:29 lab postfix/cleanup[10206]: 841DE40068: milter-discard:
>>> END-OF-MESSAGE from mail.mksoft.co.il[199.203.52.126]: milter triggers
>>> DISCARD a
>>> ction; from=<koby at mksoft.co.il> <koby at mksoft.co.il> to=
>>> <admin at ofc.mksoft.co.il> <admin at ofc.mksoft.co.il> proto=ESMTP helo=<
>>> mail.mksoft.co.il>
>>>
>>>
>>>
>>>
>>>
>>> נכתב על ידי Conz, ב־25.10.2018 בשעה 10:36:
>>>
>>> Is there anything in the maillog ?
>>>
>>> Is your MTA delivering the emails or just keeping them in the hold queue
>>> ?
>>>
>>>
>>> *usually* when MS stops picking up new messages it means it cannot
>>> access the mail queue (permissions) or is looking in the wrong location.
>>>
>>>
>>>
>>>
>>> On 10/25/18 9:16 AM, Koby Peleg Hen wrote:
>>>
>>> Hello All ,
>>>
>>> Since my upgrade to 5.1.2 (yesterday) my mailscanner stop function (not
>>> scanning)
>>>
>>> I did not change my  mailscanner.conf which run as a milter
>>>
>>>
>>>
>>> Here is the load process :
>>>
>>>
>>> postfix   4628     1  0 Oct20 ?        00:00:00 MailScanner: starting
>>> child
>>> postfix   5740     1  0 16:10 ?        00:00:00 MSMilter Daemon
>>> postfix   5744  5740  0 16:10 ?        00:00:00 MSMilter Daemon
>>> postfix   5745  5740  0 16:10 ?        00:00:00 MSMilter Daemon
>>> postfix   5746  5740  0 16:10 ?        00:00:00 MSMilter Daemon
>>> postfix   5747  5740  0 16:10 ?        00:00:00 MSMilter Daemon
>>> postfix   5748  5740  0 16:10 ?        00:00:00 MSMilter Daemon
>>> postfix   7309  2463  0 16:26 ?        00:00:00 anvil -l -t unix -u -c
>>> root      7784  7464  0 16:39 pts/1    00:00:00 grep --color=auto post*
>>> postfix  22102  4628  0 13:07 ?        00:00:34 MailScanner: waiting for
>>> messages
>>> postfix  28635  2463  0 13:46 ?        00:00:00 qmgr -l -t unix -u
>>> postfix  30060  2463  0 15:32 ?        00:00:00 pickup -l -t unix -u -c
>>> postfix  30150  2463  0 15:36 ?        00:00:00 tlsmgr -l -t unix -u -c
>>> postfix  30775  4628  0 15:41 ?        00:00:34 MailScanner: waiting for
>>> messages
>>>
>>>
>>>
>>> It is seen that some thing went wrong
>>>
>>>
>>> Any clue...
>>>
>>>
>>> Koby Peleg Hen
>>>
>>>
>>>
>>>
>>> --
>>> MailScanner mailing list
>>> mailscanner at lists.mailscanner.info
>>> http://lists.mailscanner.info/mailman/listinfo/mailscanner
>>>
>>>
>>
>> --
>> Shawn Iverson, CETL
>> Director of Technology
>> Rush County Schools
>> 765-932-3901 option 7
>> iversons at rushville.k12.in.us
>>
>>
>>
>>
>>
>>
>> --
>> MailScanner mailing list
>> mailscanner at lists.mailscanner.info
>> http://lists.mailscanner.info/mailman/listinfo/mailscanner
>>
>>
>
> --
> Shawn Iverson, CETL
> Director of Technology
> Rush County Schools
> 765-932-3901 option 7
> iversons at rushville.k12.in.us
>
>
>

-- 
Shawn Iverson, CETL
Director of Technology
Rush County Schools
765-932-3901 option 7
iversons at rushville.k12.in.us
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://lists.mailscanner.info/pipermail/mailscanner/attachments/20181025/9f80da5e/attachment.html>

More information about the MailScanner mailing list