Max Children > 1: same message gets delivered more than once

[Beat Jucker]

>   - when I define e.g. "Max Children = 3" there are three children started
>     *BUT* the same message gets delivered also N times (in this case N=3) ...
>     --> NOK
>
> I don't know how the children of MailScanner manages the processing of
> the messages in the hold queue (I'm using postfix but this shouldn't matter).
> Do I have a MailScanner locking problem?

I have tried to encircle the problem. There seems to be a locking
problem @ Solaris 9 (at least our version?)

# uname -a
SunOS cicero2 5.9 Generic_118558-03 sun4u sparc SUNW,UltraAX-i2
(full patched, using /usr/perl5/5.6.1)

I have modified MailScanner modules (additional debug statements) to get
some more details. Unfortunately perl is not one of my first / second
languages I speak fluently ...


Initialisation (Max Children = 2):
  May 10 10:00:08 cicero2 MailScanner[24151]: MailScanner E-Mail Virus Scanner version 4.41.3 starting...
  May 10 10:00:08 cicero2 MailScanner[24151]: Read 120 hostnames from the phishing whitelist
  May 10 10:00:08 cicero2 MailScanner[24151]: lock.pl sees Config  LockType =  flock
  May 10 10:00:08 cicero2 MailScanner[24151]: lock.pl sees have_module =  0
  May 10 10:00:08 cicero2 MailScanner[24151]: Using locktype = flock
  May 10 10:00:19 cicero2 MailScanner[24152]: MailScanner E-Mail Virus Scanner version 4.41.3 starting...
  May 10 10:00:19 cicero2 MailScanner[24152]: Read 120 hostnames from the phishing whitelist
  May 10 10:00:19 cicero2 MailScanner[24152]: lock.pl sees Config  LockType =  flock
  May 10 10:00:19 cicero2 MailScanner[24152]: lock.pl sees have_module =  0
  May 10 10:00:19 cicero2 MailScanner[24152]: Using locktype = flock


first instance fetches message in hold queue:
  May 10 10:00:25 cicero2 MailScanner[24152]: DBG Searching /var/spool/postfix/hold for messages
  May 10 10:00:25 cicero2 MailScanner[24152]: DBG Trying to lock message  BACE376C0A.5E46B
  May 10 10:00:25 cicero2 MailScanner[24152]: DBG lock FileHandle=GLOB(0xca37a4) /var/spool/postfix/hold/B/BACE376C0A
  May 10 10:00:25 cicero2 MailScanner[24152]: DBG fh=FileHandle=GLOB(0xca37a4) fn=+</var/spool/postfix/hold/B/BACE376C0A
  May 10 10:00:25 cicero2 MailScanner[24152]: Using flock() to lock +</var/spool/postfix/hold/B/BACE376C0A
  May 10 10:00:25 cicero2 MailScanner[24152]: DBG got hdlock
  May 10 10:00:25 cicero2 MailScanner[24152]: DBG fh=FileHandle=GLOB(0xca70f0) fn=>/var/spool/MailScanner/incoming/24152/BACE376C0A.5E46B.header
  May 10 10:00:25 cicero2 MailScanner[24152]: Using flock() to lock >/var/spool/MailScanner/incoming/24152/BACE376C0A.5E46B.header
  May 10 10:00:25 cicero2 MailScanner[24152]: New Batch: Scanning 1 messages, 784 bytes
  May 10 10:00:25 cicero2 MailScanner[24152]: Saved archive copies of BACE376C0A.5E46B
  May 10 10:00:25 cicero2 MailScanner[24152]: Spam Checks: Starting
  May 10 10:00:26 cicero2 MailScanner[24152]: Virus and Content Scanning: Starting


second instance gets same message (even first instance didn't release lock):
  May 10 10:00:26 cicero2 MailScanner[24151]: DBG Searching /var/spool/postfix/hold for messages
  May 10 10:00:26 cicero2 MailScanner[24151]: DBG Trying to lock message  BACE376C0A.8B6F4
  May 10 10:00:26 cicero2 MailScanner[24151]: DBG lock FileHandle=GLOB(0xca3910) /var/spool/postfix/hold/B/BACE376C0A
  May 10 10:00:26 cicero2 MailScanner[24151]: DBG fh=FileHandle=GLOB(0xca3910) fn=+</var/spool/postfix/hold/B/BACE376C0A
  May 10 10:00:26 cicero2 MailScanner[24151]: Using flock() to lock +</var/spool/postfix/hold/B/BACE376C0A
  May 10 10:00:26 cicero2 MailScanner[24151]: DBG got hdlock
  May 10 10:00:26 cicero2 MailScanner[24151]: DBG fh=FileHandle=GLOB(0xca47ec) fn=>/var/spool/MailScanner/incoming/24151/BACE376C0A.8B6F4.header
  May 10 10:00:26 cicero2 MailScanner[24151]: Using flock() to lock >/var/spool/MailScanner/incoming/24151/BACE376C0A.8B6F4.header
  May 10 10:00:26 cicero2 MailScanner[24151]: New Batch: Scanning 1 messages, 784 bytes
  May 10 10:00:26 cicero2 MailScanner[24151]: Saved archive copies of BACE376C0A.8B6F4
  May 10 10:00:26 cicero2 MailScanner[24151]: Spam Checks: Starting
  May 10 10:00:27 cicero2 MailScanner[24151]: Virus and Content Scanning: Starting

final processing:
  May 10 10:00:30 cicero2 MailScanner[24152]: DBG fh=FileHandle=GLOB(0xceb728) fn=+>/var/spool/postfix/incoming/temp-24152-BACE376C0A.5E46B
  May 10 10:00:30 cicero2 MailScanner[24152]: Using flock() to lock +>/var/spool/postfix/incoming/temp-24152-BACE376C0A.5E46B
  May 10 10:00:30 cicero2 MailScanner[24152]: Requeue: BACE376C0A.5E46B to 7D2CC76C2C
  May 10 10:00:30 cicero2 MailScanner[24152]: Uninfected: Delivered 1 messages
  May 10 10:00:30 cicero2 MailScanner[24152]: DBG Searching /var/spool/postfix/hold for messages

  May 10 10:00:31 cicero2 MailScanner[24151]: DBG fh=FileHandle=GLOB(0xceb7bc) fn=+>/var/spool/postfix/incoming/temp-24151-BACE376C0A.8B6F4
  May 10 10:00:31 cicero2 MailScanner[24151]: Using flock() to lock +>/var/spool/postfix/incoming/temp-24151-BACE376C0A.8B6F4
  May 10 10:00:31 cicero2 MailScanner[24151]: Requeue: BACE376C0A.8B6F4 to 2ED5076C2C
  May 10 10:00:31 cicero2 MailScanner[24151]: Uninfected: Delivered 1 messages
  May 10 10:00:31 cicero2 MailScanner[24151]: DBG Searching /var/spool/postfix/hold for messages

Regards
-- Beat

------------------------ MailScanner list ------------------------
To unsubscribe, email jiscmail at jiscmail.ac.uk with the words:
'leave mailscanner' in the body of the email.
Before posting, read the Wiki (http://wiki.mailscanner.info/) and
the archives (http://www.jiscmail.ac.uk/lists/mailscanner.html).

Support MailScanner development - buy the book off the website!