"spontaneous" re-appearance of .db (and source text!) files

classic Classic list List threaded Threaded
5 messages Options
Reply | Threaded
Open this post in threaded view
|

"spontaneous" re-appearance of .db (and source text!) files

dave@powerstandards.com
I am seeing a very strange effect. I documented it from the command line
below.

I am running on an embedded system.  What we are trying to do is whitelist
a very short list of recipients.

I am trying to set up some header and address verification checks, and
will soon have written about that in another thread.  In order to simplify
THAT (delivery) problem, I removed the verification and check from the
pipeline.  However, the sender access check just wouldn't go away!

So I removed the .db file and text file it is generated from.

It seems that postmap re-creates the .db *AND TEXT* files (after
expressing some unhappiness) every time there is a mail delivery attempt!


Note: In the process of trying to debug this, I ran across the "verify
database" docs.  Given that the list of recipients is short, I have turned
that off. (But not until AFTER I started seeing the phenomenon below.)

$ grep address main.cf
address_verify_map=

I am tempted to consider this:

a) the effect of media corruption--in fact, just here seeking confirmation
that this is an unknown phenomenon--but it has persisted across numerous
postfix reloads, restarts and even a reboot.

The other possibility is:

b) postmap is recreating the files based on some (possible corrupted)
cached database somewhere, and it is some kind of BerkeleyDB bug, but I
can't track that down (despite much googling) if it is the case.  The
mystery here is that it also recreates the text file!

Any ideas?  Anybody ever seen this before?  I have googled it, but to no
avail.

Thanks,

Dave

This shows the files re-appearing, a log watch while attempting to deliver
mail, and the build info for postmap.

1)
* The db file AND text file exist and are removed
$ ls -l sender_access2*
-rw-r--r--    1 root     root            84 Feb 13 17:21 sender_access2
-rw-r--r--    1 root     root         12288 Feb 13 17:21 sender_access2.db
$ rm -f sender_access2*
$ ls -l sender_access2*
ls: sender_access2*: No such file or directory

2)
* There is no mention of them in main.cf
$ grep sender_access2 main.cf

3)
* This is what is running
$ ps -edalf | grep postfix
 4901 postfix  pickup -l -t fifo -u -o
receive_override_options=no_header_body_checks
14549 root     grep postfix
15597 root     /usr/libexec/postfix/master
15609 postfix  qmgr -l -t fifo -u
16057 postfix  tlsmgr -l -t unix -u

4)
**
* after attempting to receive an email,
* THE FILES HAVE RE-APPEARED
**
$ ls -l sender_access2*
-rw-r--r--    1 root     root           111 Feb 14 08:47 sender_access2
-rw-r--r--    1 root     root         12288 Feb 14 08:47 sender_access2.db

5)
***
* This is what I saw when I watched a log tail.
* I believe there is a message for each "postmap" spawned and the number
of duplicates increases by one for
* each daemon.  It is preceded by messages to the effect that the file is
missing.
***
Every 5s: grep postfix /var/log/messages

                        2014-02-14 08:47:21

Feb 14 08:47:11 P1234567 mail.warn postfix/postmap[16487]: warning:
/etc/postfix/sender_access2.db: duplicate entry: "[hidden email]"
Feb 14 08:47:13 P1234567 mail.warn postfix/postmap[16499]: warning:
/etc/postfix/sender_access2.db: duplicate entry: "[hidden email]"
^C
$


* This is the build info for postmap:

$ postmap -sv hash:/etc/postfix/sender_access2
postmap: name_mask: ipv4
postmap: inet_addr_local: configured 4 IPv4 addresses
postmap: Compiled against Berkeley DB: 4.4.20?
postmap: Run-time linked against Berkeley DB: 4.4.20?
postmap: dict_open: hash:/etc/postfix/sender_access2
[list of addresses]











Reply | Threaded
Open this post in threaded view
|

Re: "spontaneous" re-appearance of .db (and source text!) files

Wietse Venema
[hidden email]:
> Feb 14 08:47:11 P1234567 mail.warn postfix/postmap[16487]: warning:
> /etc/postfix/sender_access2.db: duplicate entry: "[hidden email]"
> Feb 14 08:47:13 P1234567 mail.warn postfix/postmap[16499]: warning:
> /etc/postfix/sender_access2.db: duplicate entry: "[hidden email]"

Why are you running postmap every 5 seconds?

        Wietse
Reply | Threaded
Open this post in threaded view
|

Re: "spontaneous" re-appearance of .db (and source text!) files

dave@powerstandards.com
In reply to this post by dave@powerstandards.com
Hi Wietse,

Let me start by saying thank you for this software!!

> Why are you running postmap every 5 seconds?

I am not (as far as I know--well, clearly I am but I don't know why), at
least not on purpose.  I did not notice it myself until I started trying
to debug this issue.

The output you referred to is grepping "postfix" through a tail of the
syslog file.  When I try to send an email to the device (which is
currently not being delivered, but that's in the other, upcoming,thread),
this is what happens.

It seems to serially spawn a bunch of postmap processes in response to one
attempted delivery, (perhaps because of the db errors)?  It could also
have something to do with the issue in the thread I am about to post, but
I doubt it.  (postfix starts up with 4 ipv4 addresses.)

When postfix starts, it has always seemed to start up about eight
processes. I have not gotten to "tuning" yet.  I am going for a very lean
yet VERY secure implementation which can nevertheless handle gmail, etc.

(Note: I am a C programmer, not an admin.  This is all kind of foreign to
me.)

Thanks again!

Dave




> [hidden email]:
>> Feb 14 08:47:11 P1234567 mail.warn postfix/postmap[16487]: warning:
/etc/postfix/sender_access2.db: duplicate entry: "[hidden email]" Feb 14
08:47:13 P1234567 mail.warn postfix/postmap[16499]: warning:
/etc/postfix/sender_access2.db: duplicate entry: "[hidden email]"
> Why are you running postmap every 5 seconds?
> Wietse




Reply | Threaded
Open this post in threaded view
|

Re: "spontaneous" re-appearance of .db (and source text!) files

dave@powerstandards.com
In reply to this post by Wietse Venema

Hi Wietse,

This is a syslog snapshot of the situation a few seconds earlier:

* postmap processes dying because of a missing file (remember, there is no
mention of the db file in the current configuration)
* other postmap processes creating/populating the db file "N" times, ergo
the duplicate entry messages
* some process creates the text file: it may do it once, or overwrite in
"N" times.  Not sure which.

Every 5s: grep postfix /var/log/messages                                  
                                                                         
                        2014-02-14 12:45:44

Feb 14 12:45:31 P1234567 mail.crit postfix/postmap[19197]: fatal: open
/etc/postfix/sender_access2: No such file or directory
Feb 14 12:45:34 P1234567 mail.crit postfix/postmap[19227]: fatal: open
/etc/postfix/sender_access2: No such file or directory
Feb 14 12:45:42 P1234567 mail.warn postfix/postmap[19288]: warning:
/etc/postfix/sender_access2.db: duplicate entry: "[hidden email]"
Feb 14 12:45:42 P1234567 mail.warn postfix/postmap[19288]: warning:
/etc/postfix/sender_access2.db: duplicate entry: "[hidden email]"
Feb 14 12:45:42 P1234567 mail.warn postfix/postmap[19288]: warning:
/etc/postfix/sender_access2.db: duplicate entry: "[hidden email]"
Feb 14 12:45:43 P1234567 mail.warn postfix/postmap[19277]: warning:
/etc/postfix/sender_access2.db: duplicate entry: "[hidden email]"
Feb 14 12:45:43 P1234567 mail.warn postfix/postmap[19277]: warning:
/etc/postfix/sender_access2.db: duplicate entry: "[hidden email]"
Feb 14 12:45:43 P1234567 mail.warn postfix/postmap[19277]: warning:
/etc/postfix/sender_access2.db: duplicate entry: "[hidden email]"
Feb 14 12:45:43 P1234567 mail.warn postfix/postmap[19277]: warning:
/etc/postfix/sender_access2.db: duplicate entry: "[hidden email]"
Feb 14 12:45:43 P1234567 mail.warn postfix/postmap[19277]: warning:
/etc/postfix/sender_access2.db: duplicate entry: "[hidden email]"
Feb 14 12:45:43 P1234567 mail.warn postfix/postmap[19277]: warning:
/etc/postfix/sender_access2.db: duplicate entry: "[hidden email]"


> [hidden email]:
>> Feb 14 08:47:11 P1234567 mail.warn postfix/postmap[16487]: warning:
>> /etc/postfix/sender_access2.db: duplicate entry: "[hidden email]"
>> Feb 14 08:47:13 P1234567 mail.warn postfix/postmap[16499]: warning:
>> /etc/postfix/sender_access2.db: duplicate entry: "[hidden email]"
>
> Why are you running postmap every 5 seconds?
>
> Wietse
>


Reply | Threaded
Open this post in threaded view
|

Re: "spontaneous" re-appearance of .db (and source text!) files

Wietse Venema
[hidden email]:
> Hi Wietse,
>
> This is a syslog snapshot of the situation a few seconds earlier:
> * postmap processes dying because of a missing file (remember, there is no
> mention of the db file in the current configuration)
> * other postmap processes creating/populating the db file "N" times, ergo
> the duplicate entry messages
> * some process creates the text file: it may do it once, or overwrite in
> "N" times.  Not sure which.

Postfix DOES NOT spontaneously run postmap commands.  YOU need to
find out what is running postmap commands and stop it.

        Wietse