Dear Sir,
Thank you for your attention, and I apologize for my clumsiness.
We are in fact running 2.8.2 on FC3 not 5.
There is no chrooting, this is a vanilla install from your site.
Here are the complete logs for 2 failures and 1 success.
The sending MTA in question bemta8, usually connects 3 times at 9am
and 13 pm. 1 process at each time often dies off, leaving 2 to
'complete'.
The first two logs below are 2 failures at 9:02am 10.02.2015.
The third log is a success at 13:02 pm on the same day.
I believe all relevant logs are recorded below.
Every hour on the hour aliases are upgraded and newaliases run. When
this happens logs show a whole mess of smtp and smtpd's recording that the
hash table has changed and that the process is restarting. I thought this
might be the problem, but in looking at many other such moments of table
updates, there are no failures. SO the evidence against table hash
updates looks damning below, but I believe it is coincidental, but perhaps
you know better. The updates are done by scping the new text files over
from a master server once an hour and running newaliases.
Homer
1.) Failure, no call to qmgr. Notice table hash updates.
Oct 2 09:02:00 light postfix/smtpd[1691]: connect from
mail1.bemta8.messagelabs.com[216.82.243.205]
Oct 2 09:02:00 light postfix/smtpd[1691]: setting up TLS connection from
mail1.bemta8.messagelabs.com[216.82.243.205]
Oct 2 09:02:00 light postfix/smtpd[1691]: Anonymous TLS connection established
from mail1.bemta8.messagelabs.com[216.82.243.205]: TLSv1 with cipher
DHE-RSA-AES256-SHA (256/256 bits)
Oct 2 09:02:08 light postfix/smtpd[1691]: CC97480258A:
client=mail1.bemta8.messagelabs.com[216.82.243.205]
Oct 2 09:02:15 light postfix/smtpd[1691]: disconnect from
mail1.bemta8.messagelabs.com[216.82.243.205]
Oct 2 09:02:15 light postfix/smtpd[1691]: table
hash:/etc/aliases(0,lock|fold_fix) has changed -- restarting
Oct 2 09:02:08 light postfix/smtpd[1691]: CC97480258A:
client=mail1.bemta8.messagelabs.com[216.82.243.205]
Oct 2 09:02:08 light postgrey[28442]: CC97480258A: action=pass, reason=client AWL, client_name=mail1.bemta8.messagelabs.com, client_address=216.82.243.205, sender=ssrs_d...@corning.com, recipient=d...@howellplastics.com
Oct 2 09:02:09 light postfix/cleanup[1699]: CC97480258A: message-id=<628169e783974a3785796a8c12bdf...@na.corning.com>
2.) Second failure, notice connection time is identical. Notice table
hash update.
Oct 2 09:02:00 light postfix/smtpd[1717]: connect from
mail1.bemta8.messagelabs.com[216.82.243.205]
Oct 2 09:02:00 light postfix/smtpd[1717]: setting up TLS connection from
mail1.bemta8.messagelabs.com[216.82.243.205]
Oct 2 09:02:00 light postfix/smtpd[1717]: Anonymous TLS connection established
from mail1.bemta8.messagelabs.com[216.82.243.205]: TLSv1 with cipher
DHE-RSA-AES256-SHA (256/256 bits)
Oct 2 09:02:10 light postfix/smtpd[1717]: 363FA7DFC4:
client=mail1.bemta8.messagelabs.com[216.82.243.205]
Oct 2 09:02:16 light postfix/smtpd[1717]: disconnect from
mail1.bemta8.messagelabs.com[216.82.243.205]
Oct 2 09:02:16 light postfix/smtpd[1717]: table
hash:/etc/aliases(0,lock|fold_fix) has changed -- restarting
Oct 2 09:02:10 light postfix/smtpd[1717]: 363FA7DFC4:
client=mail1.bemta8.messagelabs.com[216.82.243.205]
Oct 2 09:02:10 light postgrey[28442]: 363FA7DFC4: action=pass, reason=client AWL, client_name=mail1.bemta8.messagelabs.com, client_address=216.82.243.205, sender=ssrs_d...@corning.com, recipient=k...@howellpkg.com
Oct 2 09:02:10 light postgrey[28442]: 363FA7DFC4: action=pass, reason=client AWL, client_name=mail1.bemta8.messagelabs.com, client_address=216.82.243.205, sender=ssrs_d...@corning.com, recipient=k...@howellpkg.com
Oct 2 09:02:10 light postgrey[28442]: 363FA7DFC4: action=pass, reason=client AWL, client_name=mail1.bemta8.messagelabs.com, client_address=216.82.243.205, sender=ssrs_d...@corning.com, recipient=r...@howellpkg.com
Oct 2 09:02:10 light postgrey[28442]: 363FA7DFC4: action=pass, reason=client AWL, client_name=mail1.bemta8.messagelabs.com, client_address=216.82.243.205, sender=ssrs_d...@corning.com, recipient=k...@howellpkg.com
Oct 2 09:02:10 light postgrey[28442]: 363FA7DFC4: action=pass, reason=client AWL, client_name=mail1.bemta8.messagelabs.com, client_address=216.82.243.205, sender=ssrs_d...@corning.com, recipient=k...@howellpkg.com
Oct 2 09:02:10 light postfix/cleanup[1696]: 363FA7DFC4: message-id=<628169e783974a3785796a8c12bdf...@na.corning.com>
3.) Third time at 13:02pm no failure. Notice absence of table hash.
Oct 2 13:01:21 light postfix/smtpd[6965]: connect from
mail1.bemta12.messagelabs.com[216.82.251.7]
Oct 2 13:01:21 light postfix/smtpd[6965]: setting up TLS connection from
mail1.bemta12.messagelabs.com[216.82.251.7]
Oct 2 13:01:21 light postfix/smtpd[6965]: Anonymous TLS connection established
from mail1.bemta12.messagelabs.com[216.82.251.7]: TLSv1 with cipher
DHE-RSA-AES256-SHA (256/256 bits)
Oct 2 13:01:21 light postfix/smtpd[6965]: EF4AF7C0A3:
client=mail1.bemta12.messagelabs.com[216.82.251.7]
Oct 2 13:01:28 light postfix/smtpd[6965]: disconnect from
mail1.bemta12.messagelabs.com[216.82.251.7]
Oct 2 13:01:21 light postfix/smtpd[6965]: EF4AF7C0A3:
client=mail1.bemta12.messagelabs.com[216.82.251.7]
Oct 2 13:01:22 light postgrey[28442]: EF4AF7C0A3: action=pass, reason=client AWL, client_name=mail1.bemta12.messagelabs.com, client_address=216.82.251.7, sender=ssrs_d...@corning.com, recipient=k...@howellpkg.com
Oct 2 13:01:22 light postgrey[28442]: EF4AF7C0A3: action=pass, reason=client AWL, client_name=mail1.bemta12.messagelabs.com, client_address=216.82.251.7, sender=ssrs_d...@corning.com, recipient=k...@howellpkg.com
Oct 2 13:01:22 light postgrey[28442]: EF4AF7C0A3: action=pass, reason=client AWL, client_name=mail1.bemta12.messagelabs.com, client_address=216.82.251.7, sender=ssrs_d...@corning.com, recipient=k...@howellpkg.com
Oct 2 13:01:22 light postgrey[28442]: EF4AF7C0A3: action=pass, reason=client AWL, client_name=mail1.bemta12.messagelabs.com, client_address=216.82.251.7, sender=ssrs_d...@corning.com, recipient=k...@howellpkg.com
Oct 2 13:01:22 light postgrey[28442]: EF4AF7C0A3: action=pass, reason=client AWL, client_name=mail1.bemta12.messagelabs.com, client_address=216.82.251.7, sender=ssrs_d...@corning.com, recipient=r...@howellpkg.com
Oct 2 13:01:22 light postfix/cleanup[6973]: EF4AF7C0A3: message-id=<0c2a64710cf142379db5822ff4e52...@na.corning.com>
Oct 2 13:01:23 light postfix/qmgr[5882]: EF4AF7C0A3:
from=<ssrs_d...@corning.com>, size=148883, nrcpt=6 (queue active)
Oct 2 13:01:23 light postfix/smtp[6726]: EF4AF7C0A3:
to=<ji...@popdirect.lightlink.com>, orig_to=<j...@howellpkg.com>,
relay=popdirect.lightlink.com[64.57.176.14]:25, conn_use=11, delay=1.5,
delays=1.4/0/0/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 0E974C7C3A7)
Oct 2 13:01:23 light postfix/smtp[6726]: EF4AF7C0A3:
to=<k...@popdirect.lightlink.com>, orig_to=<r...@howellpkg.com>,
relay=popdirect.lightlink.com[64.57.176.14]:25, conn_use=11, delay=1.5,
delays=1.4/0/0/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 0E974C7C3A7)
Oct 2 13:01:23 light postfix/smtp[6726]: EF4AF7C0A3:
to=<ks...@popdirect.lightlink.com>, orig_to=<k...@howellpkg.com>,
relay=popdirect.lightlink.com[64.57.176.14]:25, conn_use=11, delay=1.5,
delays=1.4/0/0/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 0E974C7C3A7)
Oct 2 13:01:23 light postfix/smtp[6726]: EF4AF7C0A3:
to=<k...@popdirect.lightlink.com>, orig_to=<k...@howellpkg.com>,
relay=popdirect.lightlink.com[64.57.176.14]:25, conn_use=11, delay=1.5,
delays=1.4/0/0/0.05, dsn=2.0.0, status=sent (250 2.0.0 Ok: queued as 0E974C7C3A7)
Oct 2 13:01:23 light postfix/smtp[6729]: EF4AF7C0A3: to=<k...@popper.lightlink.com>,
orig_to=<k...@howellpkg.com>, relay=spam2.lightlink.com[64.57.176.13]:25,
conn_use=12, delay=2, delays=1.4/0/0.1/0.44, dsn=2.0.0, status=sent (250 Ok: queued as
849732002463)
Oct 2 13:01:23 light postfix/smtp[6729]: EF4AF7C0A3: to=<k...@popper.lightlink.com>,
orig_to=<k...@howellpkg.com>, relay=spam2.lightlink.com[64.57.176.13]:25,
conn_use=12, delay=2, delays=1.4/0/0.1/0.44, dsn=2.0.0, status=sent (250 Ok: queued as
849732002463)
Oct 2 13:01:23 light postfix/qmgr[5882]: EF4AF7C0A3: removed
------------------------------------------------------------------------
Homer Wilson Smith Clean Air, Clear Water, Art Matrix - Lightlink
(607) 277-0959 A Green Earth, and Peace, Internet, Ithaca NY
ho...@lightlink.com Is that too much to ask? http://www.lightlink.com
On Sat, 17 Oct 2015, Wietse Venema wrote:
Homer Wilson Smith:
Dear Sirs,
Running postfix 2.8.2 on FC5.
We have a customer who receives two e-mails at 9:00am every
seven days from a mission critical customer of theirs.
The first e-mail is to one user, and the second is to 5.
On Oct 2, 2015, our server received the two emails, postgrey
approved of all 6 receipients, and then the email vanished into thin air
as is shown below by the absence of two postfix/qmgr lines that usually
fire up to deliver the e-mail.
The logging is incomplete. There should also be logging from the
smtpd daemon and from the cleanup daemon before the qmgr logging.
Missing logging from the qmgr or other daemons is quite common on
systems that run the qmgr chrooted, but that have no syslog socket
under the Postfix mail queue directory.
Postfix as shipped by me does not chroot daemons. Chroot should
not be used unless the necessary files are created under the
Postfix mail queue directory.
Wietse
