Welche user/group und permissions haben denn diese beiden Verzeichnisse?
lstat64("/var/www/horde/whups/lib", 0xbec65ee0) = -1 EACCES (Permission denied) lstat64("/var/www/horde/whups", 0xbec65df0) = -1 EACCES (Permission denied)
Am 2018-03-12 13:59, schrieb Carsten:
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@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@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@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