Discussion:
Bug#845750: postfix: Cleanup does not see the postfix-pcre.so.1.0.1 file (and probably others libraries)
(too old to reply)
Bartosz Rudnicki
2016-11-26 13:10:02 UTC
Permalink
Package: postfix
Version: 3.1.3-2
Severity: normal

It seems that the Postfix cleanup component has a problem with handling additional lookup types (pcre in my case). After installation "postfix-pcre" package which was required to use pcre maps, my dynamicmaps.cf has been filled by entry "pcre postfix-pcre.so.1.0.1 dict_pcre_open" that looks properly, because in /usr/lib/postfix directory appeared new file which is called the same way.

Unfortunately after the addition of new option in the main.cf file "milter_header_checks = pcre:/path/to/pcre/table" and reload postfix daemon everything seems good, until new message arrive and cleanup try to read my pcre file. The following log is generated:

--
Nov 26 12:59:57 Sirius postfix/cleanup[18352]: warning: unsupported dictionary type: pcre (/usr/lib/postfix/postfix-pcre.so.1.0.1: No such file or directory)
Nov 26 12:59:57 Sirius postfix/cleanup[18352]: error: unsupported dictionary type: pcre
--

It looks like for some reason the cleanup process can not reach new library file. Obviously the postfix-pcre.so.1.0.1 really exists in /usr/lib/postfix direcotry. I was suprised because I use also mysql lookups for virtual-domains functionality, which needs aditional library too (of course postfix-mysql library file exists in /usr/lib/postfix directory and has appropriate entry in dynamicmaps.cf) but it works properly. I figured out that major diffrence between cleanup and virtual (virtual-domains) is that the cleanup works chrooted into /var/spool/postfix directory, while the virtual not. Therefore I thouht that for some reason cleanup mistakenly looking for library into chrooted direcory, so I copied whole /usr/lib/postfix/ directory into /var/spool/postfix/usr/lib/ and manually reloaded postfix.


To my surprise logs looked different:

--
Nov 26 11:22:06 Sirius postfix/cleanup[17836]: fatal: load_library_symbols: dlopen failure loading /usr/lib/postfix/postfix-pcre.so.1.0.1: libpcre.so.3: cannot open shared object file: No such file or directory
Nov 26 11:22:07 Sirius postfix/master[17826]: warning: process /usr/lib/postfix/sbin/cleanup pid 17836 exit status 1
Nov 26 11:22:07 Sirius postfix/master[17826]: warning: /usr/lib/postfix/sbin/cleanup: bad command startup -- throttling
--

Now it looks that cleanup read properly lib file but has other troubles with handling the library itself. On this stage I am not able to manage with this bug, please take a look at this strange behavior.

-- /etc/postfix/dynamicmaps.cf --
# dict-type so-name (pathname) dict-function mkmap-function
mysql postfix-mysql.so.1.0.1 dict_mysql_open
sqlite postfix-sqlite.so.1.0.1 dict_sqlite_open
pcre postfix-pcre.so.1.0.1 dict_pcre_open

-- /usr/lib/postfix/ contents --
-rwxr-xr-x 1 root root 4347 paź 30 12:56 configure-instance.sh
lrwxrwxrwx 1 root root 23 paź 30 12:56 libpostfix-dns.so.1 -> libpostfix-dns.so.1.0.1
-rw-r--r-- 1 root root 27088 paź 30 12:56 libpostfix-dns.so.1.0.1
lrwxrwxrwx 1 root root 26 paź 30 12:56 libpostfix-global.so.1 -> libpostfix-global.so.1.0.1
-rw-r--r-- 1 root root 277152 paź 30 12:56 libpostfix-global.so.1.0.1
lrwxrwxrwx 1 root root 26 paź 30 12:56 libpostfix-master.so.1 -> libpostfix-master.so.1.0.1
-rw-r--r-- 1 root root 39576 paź 30 12:56 libpostfix-master.so.1.0.1
lrwxrwxrwx 1 root root 23 paź 30 12:56 libpostfix-tls.so.1 -> libpostfix-tls.so.1.0.1
-rw-r--r-- 1 root root 103472 paź 30 12:56 libpostfix-tls.so.1.0.1
lrwxrwxrwx 1 root root 24 paź 30 12:56 libpostfix-util.so.1 -> libpostfix-util.so.1.0.1
-rw-r--r-- 1 root root 260504 paź 30 12:56 libpostfix-util.so.1.0.1
-rwxr-xr-x 1 root root 13052 paź 30 12:56 postfix_groups.pl
-rw-r--r-- 1 root root 18864 paź 30 12:56 postfix-mysql.so.1.0.1
-rw-r--r-- 1 root root 18680 paź 30 12:56 postfix-pcre.so.1.0.1
-rw-r--r-- 1 root root 14624 paź 30 12:56 postfix-sqlite.so.1.0.1
drwxr-xr-x 2 root root 4096 lis 7 21:19 sbin


-- System Information:
Debian Release: stretch/sid
APT prefers testing
APT policy: (500, 'testing')
Architecture: amd64 (x86_64)

Kernel: Linux 4.7.0-1-amd64 (SMP w/4 CPU cores)
Locale: LANG=pl_PL.UTF-8, LC_CTYPE=pl_PL.UTF-8 (charmap=UTF-8)
Shell: /bin/sh linked to /bin/dash
Init: systemd (via /run/systemd/system)

Versions of packages postfix depends on:
ii adduser 3.115
ii cpio 2.11+dfsg-5
ii debconf [debconf-2.0] 1.5.59
ii dpkg 1.18.10
ii init-system-helpers 1.45
ii libc6 2.24-3
ii libdb5.3 5.3.28-12
ii libicu57 57.1-4
ii libsasl2-2 2.1.26.dfsg1-15
ii libsqlite3-0 3.14.2-1+b1
ii libssl1.0.2 1.0.2j-1
ii lsb-base 9.20160629
ii netbase 5.3
ii ssl-cert 1.0.38

Versions of packages postfix recommends:
ii python3 3.5.1-4

Versions of packages postfix suggests:
ii bsd-mailx [mail-reader] 8.1.2-0.20160123cvs-3
ii dovecot-core [dovecot-common] 1:2.2.25-1
ii libsasl2-modules 2.1.26.dfsg1-15
ii mutt [mail-reader] 1.7.0-6
pn postfix-cdb <none>
pn postfix-doc <none>
pn postfix-ldap <none>
ii postfix-mysql 3.1.3-2
ii postfix-pcre 3.1.3-2
pn postfix-pgsql <none>
ii procmail 3.22-25
pn resolvconf <none>
pn sasl2-bin <none>
pn ufw <none>

-- debconf information excluded
Scott Kitterman
2016-11-26 15:20:01 UTC
Permalink
Please check and make sure you have a tab after pcre. For some reason my mail client doesn't see it there.

-- /etc/postfix/dynamicmaps.cf --
# dict-type so-name (pathname) dict-function mkmap-function
mysql postfix-mysql.so.1.0.1 dict_mysql_open
sqlite postfix-sqlite.so.1.0.1 dict_sqlite_open
pcre postfix-pcre.so.1.0.1 dict_pcre_open

Next I would take all services out of the chroot and restart postfix. If that solves it, we'll need to figure out why.

Scott K
Bartosz Rudnicki
2016-11-26 18:00:01 UTC
Permalink
Yes, there is a tab character after pcre.

I set "chroot" option to "n" for all services in the master.cf and
restarted postfix.

Now, during sending a message, the following messages filling up the log
file:

Nov 26 18:11:45 Sirius postfix/cleanup[1723]: error: open
/etc/postfix/pcre/auth_policies: Permission denied
Nov 26 18:11:45 Sirius postfix/cleanup[1723]: warning:
pcre:/etc/postfix/pcre/auth_policies is unavailable. open
/etc/postfix/pcre/auth_policies: Permission denied
Nov 26 18:11:45 Sirius postfix/cleanup[1723]: warning: 42B227212B6:
milter_header_checks map lookup problem -- message not accepted, try
again later

Although I set recursively 777 permissions for /etc/postfix/pcre/
directory, postfix can not reach my pcre map file.
Scott Kitterman
2016-11-26 18:10:02 UTC
Permalink
Post by Bartosz Rudnicki
Yes, there is a tab character after pcre.
I set "chroot" option to "n" for all services in the master.cf and
restarted postfix.
Now, during sending a message, the following messages filling up the log
Nov 26 18:11:45 Sirius postfix/cleanup[1723]: error: open
/etc/postfix/pcre/auth_policies: Permission denied
pcre:/etc/postfix/pcre/auth_policies is unavailable. open
/etc/postfix/pcre/auth_policies: Permission denied
milter_header_checks map lookup problem -- message not accepted, try
again later
Although I set recursively 777 permissions for /etc/postfix/pcre/
directory, postfix can not reach my pcre map file.
Did you use postmap [1] to update the map?

Scott K

[1] http://www.postfix.org/postmap.1.html
Bartosz Rudnicki
2016-11-26 18:30:01 UTC
Permalink
Update pcre map by postmap? AFAIK pcre table can not be reflected by
Berkeley DB, so it can not be uptated via postmap.
Post by Scott Kitterman
Post by Bartosz Rudnicki
Yes, there is a tab character after pcre.
I set "chroot" option to "n" for all services in the master.cf and
restarted postfix.
Now, during sending a message, the following messages filling up the log
Nov 26 18:11:45 Sirius postfix/cleanup[1723]: error: open
/etc/postfix/pcre/auth_policies: Permission denied
pcre:/etc/postfix/pcre/auth_policies is unavailable. open
/etc/postfix/pcre/auth_policies: Permission denied
milter_header_checks map lookup problem -- message not accepted, try
again later
Although I set recursively 777 permissions for /etc/postfix/pcre/
directory, postfix can not reach my pcre map file.
Did you use postmap [1] to update the map?
Scott K
[1] http://www.postfix.org/postmap.1.html
Scott Kitterman
2016-11-26 18:40:01 UTC
Permalink
Personally, I've never used PCRE maps, but my reading of the man page
indicates it is.

Scott K
Post by Bartosz Rudnicki
Update pcre map by postmap? AFAIK pcre table can not be reflected by
Berkeley DB, so it can not be uptated via postmap.
Post by Scott Kitterman
Post by Bartosz Rudnicki
Yes, there is a tab character after pcre.
I set "chroot" option to "n" for all services in the master.cf and
restarted postfix.
Now, during sending a message, the following messages filling up the log
Nov 26 18:11:45 Sirius postfix/cleanup[1723]: error: open
/etc/postfix/pcre/auth_policies: Permission denied
pcre:/etc/postfix/pcre/auth_policies is unavailable. open
/etc/postfix/pcre/auth_policies: Permission denied
milter_header_checks map lookup problem -- message not accepted, try
again later
Although I set recursively 777 permissions for /etc/postfix/pcre/
directory, postfix can not reach my pcre map file.
Did you use postmap [1] to update the map?
Scott K
[1] http://www.postfix.org/postmap.1.html
LaMont Jones
2016-11-30 00:40:02 UTC
Permalink
Post by Scott Kitterman
Post by Bartosz Rudnicki
Yes, there is a tab character after pcre.
I set "chroot" option to "n" for all services in the master.cf and
restarted postfix.
Now, during sending a message, the following messages filling up the log
Nov 26 18:11:45 Sirius postfix/cleanup[1723]: error: open
/etc/postfix/pcre/auth_policies: Permission denied
What are the permissions on /etc/postfix/pcre? That almost looks like
the postfix user is unable to access the directory.
Post by Scott Kitterman
Post by Bartosz Rudnicki
pcre:/etc/postfix/pcre/auth_policies is unavailable. open
/etc/postfix/pcre/auth_policies: Permission denied
milter_header_checks map lookup problem -- message not accepted, try
again later
Although I set recursively 777 permissions for /etc/postfix/pcre/
directory, postfix can not reach my pcre map file.
Try 755 -- postfix is picky about world writable directories, iirc.
Post by Scott Kitterman
Did you use postmap [1] to update the map?
pcre maps do not need postmap compilation (nor does postmap accept such
requests.)

The next thing to do would be to add some -v options (3 or 4 of them) to
the cleanup line in master.cf and see what it has to spew into the logs.

FWIW, pcre maps seem to work just fine for me in 3.1.3-4.

lamont
Bartosz Rudnicki
2016-11-30 18:40:02 UTC
Permalink
Post by LaMont Jones
Post by Scott Kitterman
Post by Bartosz Rudnicki
Yes, there is a tab character after pcre.
I set "chroot" option to "n" for all services in the master.cf and
restarted postfix.
Now, during sending a message, the following messages filling up the log
Nov 26 18:11:45 Sirius postfix/cleanup[1723]: error: open
/etc/postfix/pcre/auth_policies: Permission denied
What are the permissions on /etc/postfix/pcre? That almost looks like
the postfix user is unable to access the directory.
Post by Scott Kitterman
Post by Bartosz Rudnicki
pcre:/etc/postfix/pcre/auth_policies is unavailable. open
/etc/postfix/pcre/auth_policies: Permission denied
milter_header_checks map lookup problem -- message not accepted, try
again later
Although I set recursively 777 permissions for /etc/postfix/pcre/
directory, postfix can not reach my pcre map file.
Try 755 -- postfix is picky about world writable directories, iirc.
Post by Scott Kitterman
Did you use postmap [1] to update the map?
pcre maps do not need postmap compilation (nor does postmap accept such
requests.)
The next thing to do would be to add some -v options (3 or 4 of them) to
the cleanup line in master.cf and see what it has to spew into the logs.
FWIW, pcre maps seem to work just fine for me in 3.1.3-4.
lamont
First of all - I noticed that pcre complications appears only when using
"milter_header_checks"; After removing this option and replacing it with
"header_checks" and "mime_header_checks" - everything seems to work
properly.

So in order to reproduce the situation in another environment, the
milter application is needed, which has to append additional header to
the message.

I set the /etc/postfix/pcre directory permissions to 755 and repeated
attempts both for default master.cf file (default chroot settings) and
for modified master.cf file, where all commands have "chroot" option set
to NO.

Results are the same as before:

1) for default master.cf:

http://pastebin.com/raw/ukfF5Zui

2) for modified master.cf (no-chroot):

http://pastebin.com/raw/5CJZU8Ki
Bartosz Rudnicki
2016-12-03 14:20:02 UTC
Permalink
Post by Bartosz Rudnicki
Post by LaMont Jones
Post by Scott Kitterman
Post by Bartosz Rudnicki
Yes, there is a tab character after pcre.
I set "chroot" option to "n" for all services in the master.cf and
restarted postfix.
Now, during sending a message, the following messages filling up the log
Nov 26 18:11:45 Sirius postfix/cleanup[1723]: error: open
/etc/postfix/pcre/auth_policies: Permission denied
What are the permissions on /etc/postfix/pcre? That almost looks like
the postfix user is unable to access the directory.
Post by Scott Kitterman
Post by Bartosz Rudnicki
pcre:/etc/postfix/pcre/auth_policies is unavailable. open
/etc/postfix/pcre/auth_policies: Permission denied
milter_header_checks map lookup problem -- message not accepted, try
again later
Although I set recursively 777 permissions for /etc/postfix/pcre/
directory, postfix can not reach my pcre map file.
Try 755 -- postfix is picky about world writable directories, iirc.
Post by Scott Kitterman
Did you use postmap [1] to update the map?
pcre maps do not need postmap compilation (nor does postmap accept such
requests.)
The next thing to do would be to add some -v options (3 or 4 of them) to
the cleanup line in master.cf and see what it has to spew into the logs.
FWIW, pcre maps seem to work just fine for me in 3.1.3-4.
lamont
First of all - I noticed that pcre complications appears only when
using "milter_header_checks"; After removing this option and replacing
it with "header_checks" and "mime_header_checks" - everything seems to
work properly.
So in order to reproduce the situation in another environment, the
milter application is needed, which has to append additional header to
the message.
I set the /etc/postfix/pcre directory permissions to 755 and repeated
attempts both for default master.cf file (default chroot settings) and
for modified master.cf file, where all commands have "chroot" option
set to NO.
http://pastebin.com/raw/ukfF5Zui
http://pastebin.com/raw/5CJZU8Ki
I've just figured out that postfix directory had not a execute
permission for others (711), so cleanup could not read the pcre map
file. Sorry for my oversight. Now, everything seems to work fine but
obviously only for the non-chrooted cleanup instance.

Interestingly the "header_checks" and "mime_header_checks" do not need
"x" permission on /etc/postfix/ directory when cleanup works without chroot.
Bartosz Rudnicki
2016-12-07 23:30:01 UTC
Permalink
Post by Bartosz Rudnicki
Post by Bartosz Rudnicki
Post by LaMont Jones
Post by Scott Kitterman
Post by Bartosz Rudnicki
Yes, there is a tab character after pcre.
I set "chroot" option to "n" for all services in the master.cf and
restarted postfix.
Now, during sending a message, the following messages filling up the log
Nov 26 18:11:45 Sirius postfix/cleanup[1723]: error: open
/etc/postfix/pcre/auth_policies: Permission denied
What are the permissions on /etc/postfix/pcre? That almost looks like
the postfix user is unable to access the directory.
Post by Scott Kitterman
Post by Bartosz Rudnicki
pcre:/etc/postfix/pcre/auth_policies is unavailable. open
/etc/postfix/pcre/auth_policies: Permission denied
milter_header_checks map lookup problem -- message not accepted, try
again later
Although I set recursively 777 permissions for /etc/postfix/pcre/
directory, postfix can not reach my pcre map file.
Try 755 -- postfix is picky about world writable directories, iirc.
Post by Scott Kitterman
Did you use postmap [1] to update the map?
pcre maps do not need postmap compilation (nor does postmap accept such
requests.)
The next thing to do would be to add some -v options (3 or 4 of them) to
the cleanup line in master.cf and see what it has to spew into the logs.
FWIW, pcre maps seem to work just fine for me in 3.1.3-4.
lamont
First of all - I noticed that pcre complications appears only when
using "milter_header_checks"; After removing this option and
replacing it with "header_checks" and "mime_header_checks" -
everything seems to work properly.
So in order to reproduce the situation in another environment, the
milter application is needed, which has to append additional header
to the message.
I set the /etc/postfix/pcre directory permissions to 755 and repeated
attempts both for default master.cf file (default chroot settings)
and for modified master.cf file, where all commands have "chroot"
option set to NO.
http://pastebin.com/raw/ukfF5Zui
http://pastebin.com/raw/5CJZU8Ki
I've just figured out that postfix directory had not a execute
permission for others (711), so cleanup could not read the pcre map
file. Sorry for my oversight. Now, everything seems to work fine but
obviously only for the non-chrooted cleanup instance.
Interestingly the "header_checks" and "mime_header_checks" do not need
"x" permission on /etc/postfix/ directory when cleanup works without chroot.
Due to inaccurate description of the reported issue which caused
misunderstanding, I intend to describe mentioned behaviors once again,
keeping in mind the specific conditions which MUST be satisfied in order
to recreate this bug.

By default, the cleanup process works chrooted inside postfix queue
directory. Maintaining this option untouched, I am able to set
additional "header_checks" or "mime_header_checks" functionality, by
adding corresponding options in the main.cf file. For this example I
used the pcre map type which requires additional package be installed
(postfix-pcre). After installation required package and indicate testing
pcre map file (which rejects every input string) in the "header_checks"
and "mime_header_checks" options, postfix reload is needed. In this case
everything works properly - received message via smtpd is catched by
cleanup process and respectively rejected.

The undesirable behavior appears ONLY, when the "milter_header_checks"
option is used. But for this, a milter application is needed which will
append additional header. I use OpenDKIM milter which inserts DKIM
signature to the message. After assign testing pcre map to the
"milter_header_checks" option and reload postfix, the following entries
Post by Bartosz Rudnicki
Dec 7 23:13:32 Sirius postfix/cleanup[2738]: warning: unsupported
dictionary type: pcre (/usr/lib/postfix/postfix-pcre.so.1.0.1: No such
file or directory)
Dec 7 23:13:32 Sirius postfix/cleanup[2738]: error: unsupported
dictionary type: pcre
I stress once again - this error *occurs ONLY* when
"milter_header_checks" option is used. This behavior*does not appear*
with the generic (mime_)header_checks!

A temporary solution is to set the cleanup process to work in the
non-chrooted mode. Aditionaly, but after that new obstacle has appeared
- Postfix comes with "o=" /etc/postfix/ directory permission, whereby
cleanup cannot reach the map file. "chmod o+x /etc/postfix/" should
cause to this workaround works properly.

Below, I put a step by step how to reproduce this bug:

*Postfix 3.1.3 from debian repository is needed.

*Any milter application which will write header to the message is needed
- I use OpenDKIM but OpenDMARC should be faster in configuration.

1. Make sure cleanup works with true chroot option in the master.cf file.

2. Set the "smtpd_milter" option respectively to your milter
configuration *and make sure that it really writes header when message
is received by smtpd*.

3. Install the postfix-pcre package (I did not try with other additional
map types)

4. Create a testing pcre map which will catch all cases:

/.*/ REJECT If you see this statement, the before-queue
header-checks work properly

and save it somewhere into /etc/postfix/ directory.

5. Set "milter_header_checks = pcre:/etc/postfix/pcre_test_file" option
in the main.cf file.

6. Reload postfix and try send a message through smtp.


I hope that it is now clearly explained and there will be no problem
with reproduction of this behavior.

Bartosz Rudnicki

Loading...