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

Patrick Boutilier boutilpj at ednet.ns.ca
Mon Mar 12 13:46:58 UTC 2018 

On 03/12/2018 10:04 AM, Carsten wrote:
> 
> 
> 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



lstat64("/var/www/horde/whups", 0xbec65df0) = -1 EACCES (Permission denied)


suggests otherwise though. You said 777 made things work. Can you try 
giving the same right as postfix-pipe to the postfix and nobody users 
for a test?
-------------- next part --------------
A non-text attachment was scrubbed...
Name: boutilpj.vcf
Type: text/x-vcard
Size: 286 bytes
Desc: not available
URL: <https://lists.horde.org/archives/horde/attachments/20180312/87a71707/attachment.vcf>

More information about the horde mailing list