[postfix] pipe alias permission denied

Carsten horde-groupware at familie-lahme.de
Mo Mär 12 13:59:48 CET 2018


Hallo zusammen,
ich möchte unter Verwendung einer aliases pipe ein PHP-Script triggern, 
welches eine eingehende Mail verarbeitet, und bekomme ein "permission 
denied", sobald ein "require_once" getriggert wird (php interpreter).

Verwendete Software: Horde Groupware -> Modul "Whups" (Tickettracking) 
-> "whups-mail-filter"
Der gesamte Vorgang ist schon sehr kleinteilig durch die Horde 
Mailingliste gegangen, weil ich zunächst von einem Fehler dort ausging.
Hier der letzte Teil des Troubleshootings:

In der main.cf habe ich den Wert "default_privs = postfix-pipe" gesetzt.
Den Benutzer habe ich angelegt.
Die Webanwendung residiert unter /var/www/horde
Die fragliche Datei (require_once) unter 
/var/www/horde/whups/lib/Application.php
Ab ../horde/.. gilt: 750 www-data:www-horde
Die Benutzer "postfix" und "postfix-pipe" sind Mitglieder der Gruppe 
"www-horde".
Die /etc/aliases sieht so aus:
## WHUPS queue links
whups:   "|/usr/bin/whups-mail-filter -g -a carsten@[mydn.tld]e -Q 5"

In der Datei "/usr/bin/whups-mail-filter" habe ich zu Debuggingzwecken 
diese Zeilen am Anfang eingefügt
$shellex = shell_exec("logger INFO whoami: $(whoami)");
$shellex = shell_exec("logger INFO who am i: $(who am i)");
$shellex = shell_exec("touch /tmp/hallowelt.ini");

Für das weitere Debugging habe ich eine Datei "testmail" angelegt mit 
diesem Inhalt:
######################
From: root at derdapp001.[mydn.tld]
To: whups@[mydn.tld]
subject: Monitoring: Testticket

Hello World

#######################
Jetzt kann ich mit dem Befehl
"sudo -u postfix-pipe cat testmail|/usr/bin/whups-mail-filter -g -a 
carsten@[mydn.tld] -Q 5"
den Vorgang auf der Kommandozeile testen und bekomme im Whups Ticket 
System mein gewünschtes Ticket.
Nun gehe ich auf ein drittes System und sende von dort die "scharfe" 
E-Mail -also jetzt triggere ich den postfix:
#####################
root at derdapp001 ~ # sendmail whups@[mydn.tld]
subject: monitoring: testticket

Hallo welt

[ctrl]+d
#######################
Jetzt bekomme ich im syslog des mail server diesen output:
#########################
##
Mar 12 13:35:27 derdapp004 logger: INFO whoami: postfix-pipe
Mar 12 13:35:27 derdapp004 logger: INFO who am i: <=Anmerkung: leer: 
kein "parent user"
Mar 12 13:35:27 derdapp004 postfix/local[16770]: BE46441CCB: 
to=<whups at localhost>, orig_to=<whups@[mydn.tld]>, relay=local, 
delay=0.95, delays=0.02/0.01/0/0.92, dsn=5.3.0, status=bounced (Command 
died with status 255: "/usr/bin/whups-mail-filter -g -a 
carsten@[mydn.tld] -Q 5". Command output: PHP Warning: 
require_once(/var/www/horde/whups/lib/Application.php): failed to open 
stream: Permission denied in /usr/bin/whups-mail-filter on line 77 PHP 
Fatal error:  require_once(): Failed opening required 
'/var/www/horde/whups/lib/Application.php' 
(include_path='.:/usr/share/php:/usr/share/pear') in 
/usr/bin/whups-mail-filter on line 77 )
Mar 12 13:35:27 derdapp004 postfix/cleanup[16769]: B13E641CD6: 
message-id=<20180312123527.B13E641CD6@[mydn.tld]>
Mar 12 13:35:27 derdapp004 postfix/bounce[16774]: BE46441CCB: sender 
non-delivery notification: B13E641CD6
Mar 12 13:35:27 derdapp004 postfix/qmgr[16757]: B13E641CD6: from=<>, 
size=3250, nrcpt=1 (queue active)
Mar 12 13:35:27 derdapp004 postfix/qmgr[16757]: BE46441CCB: removed
Mar 12 13:35:27 derdapp004 dovecot: lda(no-reply@[mydn.tld]): 
msgid=<20180312123527.B13E641CD6@[mydn.tld]>: saved mail to INBOX
Mar 12 13:35:27 derdapp004 postfix/pipe[16777]: B13E641CD6: 
to=<no-reply@[mydn.tld]>, orig_to=<root@[mydn.tld]>, relay=dovecot, 
delay=0.14, delays=0.02/0.01/0/0.12, dsn=2.0.0, status=sent (delivered 
via dovecot service)
Mar 12 13:35:27 derdapp004 postfix/qmgr[16757]: B13E641CD6: removed
##
############################
Aus dem "touch" entsteht diese Datei:
#################
##
ll /tmp/hallo*
-rw------- 1 postfix-pipe postfix-pipe      0 Mar 12 13:35 hallowelt.ini
##
#################
Wie zu sehen ist, funktioniert der Aufruf des "require_once" in der 
whups-mail-filter auf die Application.php nicht.
Es scheint das System nicht zu interessieren, welcher Benutzer dort 
hinterlegt ist.
Alle offensichtlichen Zeichen, zeigen klar, daß der Benutzer 
"postfix-pipe" Verwendung findet.
In der Kommandozeile hat dieser auch ordenlichen Zugriff. Nur aus dem 
Postfix heraus, klappt es nicht.
Wenn ich ein 755 auf das horde-verzeichnis gebe -also "other" = 
"read&execute" gebe, so funktioniert es.
Das kann aber wohl nicht als ernsthafte Lösung gesehen werden, oder?

Ich habe noch zwei straces auf den Process.
Hier der output, wenn ich aus dem postfix komme:
####################
###
[...snip...]
gettimeofday({1520811096, 605233}, NULL) = 0
lstat64("/var/www/horde/whups/lib/Application.php", 0xbec64008) = -1 
EACCES (Permission denied)
gettimeofday({1520811096, 605766}, NULL) = 0
lstat64("/var/www/horde/whups/lib/Application.php", 0xbec63f18) = -1 
EACCES (Permission denied)
gettimeofday({1520811096, 606180}, NULL) = 0
lstat64("/var/www/horde/whups/lib/Application.php", 0xbec65fe0) = -1 
EACCES (Permission denied)
lstat64("/var/www/horde/whups/lib", 0xbec65ee0) = -1 EACCES (Permission 
denied)
lstat64("/var/www/horde/whups", 0xbec65df0) = -1 EACCES (Permission denied)
lstat64("/var/www/horde", {st_mode=S_IFDIR|0770, st_size=4096, ...}) = 0
lstat64("/var/www", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/var", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
open("/var/www/horde/whups/lib/Application.php", O_RDONLY|O_LARGEFILE) = 
-1 EACCES (Permission denied)
[...snip...]
###
####################
und der gleiche Teil, wenn ich aus der Kommandozeile per "sudo -u" komme:
####################
###
[...snip...]
ettimeofday({1520812051, 622266}, NULL) = 0
lstat64("/var/www/horde/whups/lib/Application.php", 
{st_mode=S_IFREG|0770, st_size=9232, ...}) = 0
lstat64("/var/www/horde/whups/lib", {st_mode=S_IFDIR|0770, st_size=4096, 
...}) = 0
lstat64("/var/www/horde/whups", {st_mode=S_IFDIR|0770, st_size=4096, 
...}) = 0
lstat64("/var/www/horde", {st_mode=S_IFDIR|0770, st_size=4096, ...}) = 0
lstat64("/var/www", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat64("/var", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
gettimeofday({1520812051, 624126}, NULL) = 0
open("/var/www/horde/whups/lib/Application.php", O_RDONLY|O_LARGEFILE) = 4
[...snip...]
###
####################

Wer hat hier eine Idee, was die Ursache ist? Übersehe ich noch etwas?
Welche Debug Information kann ich noch liefern?
Gruss
Carsten


Mehr Informationen über die Mailingliste postfix-users