[horde] [whups]: error on script pipe in postfix

Carsten horde-groupware at familie-lahme.de
Mon Mar 12 13:04:09 UTC 2018 


Am 12.03.2018 um 13:36 schrieb Patrick Boutilier:
> On 03/11/2018 08:52 PM, Carsten wrote:
>>
>>
>> Am 11.03.2018 um 23:57 schrieb Jan Schneider:
>>>
>>> Zitat von Carsten <horde-groupware at familie-lahme.de>:
>>>
>>>> Am 11.03.2018 um 21:05 schrieb Jan Schneider:
>>>>>
>>>>> Zitat von Carsten <horde-groupware at familie-lahme.de>:
>>>>>
>>>>>> Am 11.03.2018 um 13:07 schrieb Carsten:
>>>>>>>
>>>>>>>
>>>>>>> Am 11.03.2018 um 12:35 schrieb Carsten:
>>>>>>>>
>>>>>>>>
>>>>>>>> Am 10.03.2018 um 21:00 schrieb Jan Schneider:
>>>>>>>>>
>>>>>>>>> Zitat von Carsten <horde-groupware at familie-lahme.de>:
>>>>>>>>>
>>>>>>>>>> Am 10.03.2018 um 11:20 schrieb Jan Schneider:
>>>>>>>>>>>
>>>>>>>>>>> Zitat von Carsten <horde-groupware at familie-lahme.de>:
>>>>>>>>>>>
>>>>>>>>>>>> Am 09.03.2018 um 11:38 schrieb Jan Schneider:
>>>>>>>>>>>>>
>>>>>>>>>>>>> Zitat von Carsten <horde-groupware at familie-lahme.de>:
>>>>>>>>>>>>>
>>>>>>>>>>>>>> Hi all,
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> I try the set up whups with automated ticket generation 
>>>>>>>>>>>>>> from mails.
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> my postfix sends the incoming mail to the pipe, but 
>>>>>>>>>>>>>> returns such an error:
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> Mar  8 12:40:38 derdapp004 postfix/local[30799]: 
>>>>>>>>>>>>>> 04C7040C4C: to=<whups at localhost>, 
>>>>>>>>>>>>>> orig_to=<whups@[mydn.tdl]>, relay=local, delay=0.58, 
>>>>>>>>>>>>>> delays=0.09/0.04/0/0.45, dsn=5.3.0, status=bounced 
>>>>>>>>>>>>>> (Command died with status 255: 
>>>>>>>>>>>>>> "/usr/bin/whups-mail-filter -g". Command output: PHP 
>>>>>>>>>>>>>> Warning: 
>>>>>>>>>>>>>> require_once(/usr/share/php/www/horde/whups/lib/Application.php): 
>>>>>>>>>>>>>> failed to open stream: No such file or directory in 
>>>>>>>>>>>>>> /usr/bin/whups-mail-filter on line 73 PHP Fatal error: 
>>>>>>>>>>>>>> require_once(): Failed opening required 
>>>>>>>>>>>>>> '/usr/share/php/www/horde/whups/lib/Application.php' 
>>>>>>>>>>>>>> (include_path='.:/usr/share/php:/usr/share/pear') in 
>>>>>>>>>>>>>> /usr/bin/whups-mail-filter on line 73 )
>>>>>>>>>>>>>>
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> If I pipe with the local user (root) from the command 
>>>>>>>>>>>>>> line, it works perfect.
>>>>>>>>>>>>>> I guess it is about a missing environment o.s.
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> Can somebody advice, pls?
>>>>>>>>>>>>>>
>>>>>>>>>>>>>> br
>>>>>>>>>>>>>> Carsten
>>>>>>>>>>>>>
[..snipped out some parts, because got size warning from mailinglist..]
>>>>>>>> Checked file permissions. As described above:
>>>>>>>>
>>>>>>>> ###################
>>>>>>>> #
>>>>>>>> root at derdapp004 ~www/horde/whups/lib # pwd
>>>>>>>> /var/www/horde/whups/lib
>>>>>>>> root at derdapp004 ~www/horde/whups/lib # ll Application.php
>>>>>>>> -rwxr--r-x 1 www-data root 9169 Mar  7 11:33 Application.php
>>>>>>>> ##
>>>>>>>> ##################
>>>>>>>>
>>>>>>>> Let's check, what would be the output of a call of that file:
>>>>>>>>
>>>>>>>> #################
>>>>>>>> ##
>>>>>>>> root at derdapp004 ~www/horde/whups/lib # php -f Application.php
>>>>>>>> root at derdapp004 ~www/horde/whups/lib #
>>>>>>>> ##
>>>>>>>> #################
>>>>>>>>
>>>>>>>> Now with postfix:
>>>>>>>>
>>>>>>>> #################
>>>>>>>> ##
>>>>>>>> root at derdapp004 ~www/horde # sudo -u postfix php -f 
>>>>>>>> /var/www/horde/whups/lib/Application.php
>>>>>>>> Could not open input file: 
>>>>>>>> /var/www/horde/whups/lib/Application.php
>>>>>>>> #
>>>>>>>> ##################
>>>>>>>>
>>>>>>>> Now I did a more intense check of the permissions, using
>>>>>>>>
>>>>>>>> ##############
>>>>>>>> ##
>>>>>>>> root at derdapp004 ~www/horde/whups/lib # sudo -u postfix ls 
>>>>>>>> /var/www/horde/whups/lib
>>>>>>>> ls: cannot access /var/www/horde/whups/lib: Permission denied
>>>>>>>> root at derdapp004 ~www/horde/whups/lib # cd /var/www/horde
>>>>>>>> root at derdapp004 ~www/horde # ll
>>>>>>>> total 136
>>>>>>>> [...snipp...]
>>>>>>>> drwxr--r-- 13 www-data root  4096 Mar  7 11:33 whups
>>>>>>>> ##
>>>>>>>> ##############
>>>>>>>>
>>>>>>>> and bingo, a thing, I will never understand in the LX 
>>>>>>>> permission context: You need execute to enter a directory
>>>>>>>> Thinking about RBAC I solved it with this:
>>>>>>>> 1st: create a group "www-horde"
>>>>>>>> 2nd: put user postfix into that group
>>>>>>>> 3rd: do a "chown -R www-data:www-horde /var/www/horde"
>>>>>>>> 4th: do a "chmod -R 750 /var/www/horde"
>>>>>>>> 5th: do another test:
>>>>>>>>
>>>>>>>> #################
>>>>>>>> ##
>>>>>>>> root at derdapp004 ~www/horde # sudo -u postfix /tmp/testmail
>>>>>>>> learscreen]
>>>>>>>> Hi, my name is postfix
>>>>>>>> root at derdapp004 ~www/horde #
>>>>>>>> ##
>>>>>>>> #################
>>>>>>>>
>>>>>>>> Ticket created!! And now: be happy.... ;-)
>>>>>>>>
>>>>>>>> Thanks for You patients and help!!
>>>>>>>>
>>>>>>>> br
>>>>>>>> Carsten
>>>>>>>
>>>>>>> ok, back, where we have started. I've forgotten the test using 
>>>>>>> the mail:
>>>>>>> #######################
>>>>>>> ##
>>>>>>>
>>>>>>> <whups at localhost> (expanded from <whups@[mydn.tld]>): 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 73 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 73
>>>>>>>
>>>>>>> ##
>>>>>>> #######################
>>>>>>>
>>>>>>> *BöseFlüche*
>>>>>>>
>>>>>>> What else have I missed?
>>>>>>>
>>>>>>> br
>>>>>>> Carsten
>>>>>>
>>>>>> I did some more research and found that:
>>>>>> "...
>>>>>> postfix/main.cf
>>>>>> default_privs (default: nobody)
>>>>>> The default rights used by the local(8) delivery agent for 
>>>>>> delivery to external file or command. These rights are used when 
>>>>>> delivery is requested from an aliases(5) file that is owned by 
>>>>>> root, or when delivery is done on behalf of root. DO NOT SPECIFY 
>>>>>> A PRIVILEGED USER OR THE POSTFIX OWNER.
>>>>>> ..."
>>>>>>
>>>>>> I added two lines to the whups-mail-filter like that:
>>>>>> "...
>>>>>> <?php
>>>>>> $shellex = shell_exec("logger INFO $(whoami)");
>>>>>> echo $shellex;
>>>>>> ..."
>>>>>>
>>>>>> Which returned this in the syslog:
>>>>>> "..
>>>>>> Mar 11 13:25:58 derdapp004 logger: INFO nobody
>>>>>> ..."
>>>>>>
>>>>>> So, we are back to the permissions.
>>>>>>
>>>>>> 1st: create a new user "postfix-pipe"
>>>>>> 2nd: add it to the group "www-horde".
>>>>>> 3rd: add "default_privs = postfix-pipe" to the main.cf
>>>>>> 4th: do a postmap main.cf and a postfix reload
>>>>>> 5th: do a command line check:
>>>>>> ##############################
>>>>>> ##
>>>>>> root at derdapp004 /etc # sudo -u postfix-pipe php -f 
>>>>>> /var/www/horde/whups/lib/Application.php
>>>>>> root at derdapp004 /etc #
>>>>>> ##
>>>>>> ##############################
>>>>>> => works!
>>>>>>
>>>>>> 6th: do a mail check:
>>>>>> "...
>>>>>> Mar 11 13:54:39 derdapp004 logger: INFO postfix-pipe
>>>>>> Mar 11 13:54:40 derdapp004 postfix/local[32191]: A2D55415CC: 
>>>>>> to=<whups at localhost>, orig_to=<whups@[mydn.tld]>, relay=local, 
>>>>>> delay=0.61, delays=0.08/0.04/0/0.5, 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 76 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 76 )
>>>>>> ..."
>>>>>> => FAILS!!
>>>>>>
>>>>>> now I am totaly off.......
>>>>>
>>>>> Did you check the permissions of all parent directories too?
>>>>>
>>>> I think, I did, but let's walk through:
>>>> Toplevel "var" looks ok (other = r and x):
>>>> ###
>>>> root at derdapp004 ~www # cd /
>>>> root at derdapp004 / # ll
>>>> [...snip...]
>>>> drwxr-xr-x  14 root  root       4096 May  3  2017 var
>>>> ###
>>>>
>>>> Step into /var and check "www".
>>>> looks good, too.(other = r and x):
>>>> ###
>>>> root at derdapp004 / # cd var
>>>> root at derdapp004 /var # ll
>>>> [...snip...]
>>>> drwxr-xr-x  4 root  root  4096 May  6  2017 www
>>>> ###
>>>>
>>>> Now into www to check "horde".
>>>> From here we use group permission (www-horde = r and x)
>>>> ###
>>>> oot at derdapp004 /var # cd www
>>>> root at derdapp004 ~www # ll
>>>> drwxr-x--- 24 www-data www-horde 4096 Mar  7 11:33 horde
>>>> ###
>>>>
>>>> Next below horde is "whups":
>>>> ###
>>>> root at derdapp004 ~www # cd horde :(
>>>> root at derdapp004 ~www/horde # ll
>>>> [...snip...]
>>>> drwxr-x--- 13 www-data www-horde  4096 Mar  7 11:33 whups
>>>> ###
>>>>
>>>> Subfolder "lib":
>>>> ###
>>>> oot at derdapp004 ~www/horde # cd whups
>>>> root at derdapp004 ~www/horde/whups # ll
>>>> [..snip..]
>>>> drwxr-x--- 14 www-data www-horde 4096 Mar  7 11:33 lib
>>>> ###
>>>>
>>>> and last but nor least the file itself:
>>>> ###
>>>> root at derdapp004 ~www/horde/whups # cd lib
>>>> root at derdapp004 ~www/horde/whups/lib # ll
>>>> [...snip...]
>>>> -rwxr-x--- 1 www-data www-horde  9232 Mar 11 18:55 Application.php
>>>> ###
>>>>
>>>> I do not see any error from that point of view.
>>>>
>>>> If I do a "chmod -R 777 *" through the horde structure, it works.
>>>> I have added the "whoami" lines to the "Application.php" and it 
>>>> returns "postfix-pipe" if executed successful.
>>>>
>>>> I already checked for apparmor and selinux, but last is not active 
>>>> and first is only configured for mysql.
>>>> The server has been rebooted meanwhile, too, just to make sure the 
>>>> new user/group objects are loaded, but no change.
>>>> At the moment I am totally out of ideas, and a "777" is not really 
>>>> acceptable from my perspective.
>>>>
>>>> Any idea, how to do a "strace" on whups-mail-filter?!
>>>>
>>>> br
>>>> Carsten
>>>
>>> strace php whups-mail-filter
>>>
>> After tricking around, with how to implement this in the alias pipe, 
>> I worked out this simple solution:
>>
>> "...
>> whups:   "|strace -o /tmp/trace.log /usr/bin/whups-mail-filter -g -a 
>> carsten@[mydn.tld] -Q 5"
>> ..."
>>
>> sending a mail to the pipe creates some output including this part:
>>
>> ####################
>> ###
>> [...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...]
>> ###
>> ####################
>>
>> Well nothing surprising in the first view.
>> If I run a simple command line like
>> "...
>> sudo -u postfix-pipe strace -o /tmp/trace1.log 
>> /usr/bin/whups-mail-filter
>> ..."
>>
>> This is the output:
>>
>> ####################
>> ###
>> [...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...]
>> ###
>> ####################
>>
>> Do You see the different values in the lstat64? Where do they come from?
>> Somebody more familiar with strace output here?
>>
>
> Are you sure that postfix-pipe is the correct user? As far as I can 
> tell "default_privs" only affects local deliveries, not pipe. Try 
> changing to
>
> whups:   "|whoami > /tmp/post-user && strace -o /tmp/trace.log 
> /usr/bin/whups-mail-filter -g -a carsten@[mydn.tld] -Q 5"
>
>
> and then checking the contents of /tmp/post-user .
>
>
Hi,
I know, the thread has gotten very long and hard to read, but I checked 
this.
This is the current heading of the "whups-mail-filter":

########################
##
#!/usr/bin/php
<?php
$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");
##
########################

The output in the syslog, if triggered using postfix:
#########################
##
Mar 12 13:35:27 derdapp004 logger: INFO whoami: postfix-pipe
Mar 12 13:35:27 derdapp004 logger: INFO who am i:
##
##########################

The file:
#################
##
ll /tmp/hallo*
-rw------- 1 postfix-pipe postfix-pipe      0 Mar 12 13:35 hallowelt.ini
##
#################

No doubt, that user "postfix-pipe" is in use.

br
Carsten

More information about the horde mailing list