Problems with Freebsd 5.1, jail and php mail() function (straced)

[Emil Filipov]

Hi,

I have a FreeBSD 5.1 box with jails. Some of them are 'builded' (with make world and make distribution), others I have created 'by hand' by copying files in the jail until things start to work.

In one such 'handmade' jail I have deployed ftpd, apache with php,ssmtp. Everything seems to be working fine except for the php mail() function. 

As usual when there is no log message or warning giving a hint what is missing, I tried to strace the process.Started with creating a simple enough .php page, taken directly from a php manual:
<?php
        mail("tie at einet.bg", "My Subject", "Line 1\nLine 2\nLine 3");
        ?>
I tested it out of the jail environment and it worked. Tested it in a 'builded' jail - also works.Strace is normal.
While trying to strace it while executing within such 'handmade' jail I get some output I have never seen:


# strace -ffp 43685
accept(16,


{...}, 0xbfbffb6c)           = 0
syscall_416(0x1e, 0xbfbffb10, 0xbfbffaf0) = 0
fcntl(0, F_SETFD, FD_CLOEXEC)           = 0
getsockname(0, {...}, 0xbfbffb6c)       = 0
setsockopt(0, 0x6 /* SOL_?? */, TCP_NODELAY, 0xbfbffb30, 4) = 0
read(0, "GET /mytest.php HTTP/1.1\r\nAccept"..., 4096) = 202
syscall_416(0x1e, 0xbfbfda70, 0xbfbfda50) = 0
gettimeofday({791289914, 1091177770}, NULL) = 0
stat("/site/html/mytest.php", {st_mode=S_IFREG|0644, st_size=74, ...}) = 0
sigprocmask(SIG_BLOCK, NULL, [])        = 0
umask(077)                              = 022
umask(022)                              = 077
sigprocmask(SIG_BLOCK, NULL, [])        = 0
setitimer(ITIMER_PROF, {it_interval={0, 2047}, it_value={0, 0}}, NULL) = 0
syscall_416(0x1b, 0xbfbff800, 0xbfbff7e0) = 0
sigprocmask(SIG_UNBLOCK, [], NULL)      = 0
sigprocmask(SIG_BLOCK, NULL, [])        = 0
__getcwd("", 4095)                      = 0
chdir("")                               = 0
lstat("", {st_mode=0415, st_size=1292785156096, ...}) = 0
lstat("ќ", {st_mode=0, st_size=408021893229, ...}) = 0
lstat("c", {st_mode=0234, st_size=1653562409295, ...}) = 0
setitimer(ITIMER_PROF, {it_interval={113, 107}, it_value={232, 0}}, NULL) = 0
syscall_416(0x1b, 0xbfbfe3a0, 0xbfbfe380) = 0
sigprocmask(SIG_UNBLOCK, [], NULL)      = 0
__getcwd("", 1024)                      = 0
lstat("", {st_mode=0151060, st_size=15960098996242, ...}) = 0
lstat("", {st_mode=0, st_size=2946347565072, ...}) = 0
lstat("", {st_mode=073620, st_size=17364553302034, ...}) = 0
open("/site/html/mytest.php", O_RDONLY) = 1
fstat(1, {st_mode=023, st_size=8070450533662672128, ...}) = 0
fstat(1, {st_mode=0162755, st_size=6875142181715337580, ...}) = 0
lseek(1, 0, SEEK_CUR)                   = 0
lseek(1, 0, SEEK_SET)                   = 0
read(1, "<?php\n\tmail(\"tie at einet.bg\", \"My "..., 8192) = 74
read(1, "", 8192)                       = 0
close(1)                                = 0
pipe([1, 3])                            = 1
vfork(strace: open("/proc/...", ...): No such file or directory
)                                 = 45534
--- SIGCHLD (Child exited) ---
fcntl(3, F_GETFL)                       = 0x2 (flags O_RDWR)
close(1)                                = 0
fstat(3, {st_mode=S_IFCHR|S_ISUID|0154, st_rdev=makedev(98, 577175598), ...}) = 0
write(3, "To: tie at einet.bg\nSubject: My Sub"..., 59) = -1 EPIPE (Broken pipe)
--- SIGPIPE (Broken pipe) ---
close(3)                                = 0
wait4(45534, [WIFSIGNALED(s) && WTERMSIG(s) == 106], 0, NULL) = 45534
chdir("

Line 1
Line 2
Line 3
Line 3\");
        ?>
") = 0
sigprocmask(SIG_BLOCK, NULL, [])        = 0
sigprocmask(SIG_BLOCK, NULL, [])        = 0
sigprocmask(SIG_BLOCK, NULL, [])        = 0
sigprocmask(SIG_BLOCK, NULL, [])        = 0
sigprocmask(SIG_BLOCK, NULL, [])        = 0
sigprocmask(SIG_BLOCK, NULL, [])        = 0
sigprocmask(SIG_BLOCK, NULL, [])        = 0
sigprocmask(SIG_BLOCK, NULL, [])        = 0
sigprocmask(SIG_BLOCK, NULL, [])        = 0
sigprocmask(SIG_BLOCK, NULL, [])        = 0
sigprocmask(SIG_BLOCK, NULL, [])        = 0
sigprocmask(SIG_BLOCK, NULL, [])        = 0
sigprocmask(SIG_BLOCK, NULL, [])        = 0
sigprocmask(SIG_BLOCK, NULL, [])        = 0
sigprocmask(SIG_BLOCK, NULL, [])        = 0
setitimer(ITIMER_PROF, {it_interval={0, 2047}, it_value={0, 0}}, NULL) = 0
umask(022)                              = 022
select(1, [], NULL, NULL, {0, 674295616}) = 0 (Timeout)
write(0, "HTTP/1.1 200 OK\r\nDate: Tue, 16 D"..., 210) = 210
 (sorry for the lenghty output)

This is a trace from one of the apache processes (the one which handles the GET request for the former page). We see that everything is fine UNTIL it comes time to fork() and invoke the php interpreter. I don't understand what happens when that time comes - strace cannot follow the vfork for some reasons. Of course I have tried with other parameters also -F -v -s 100 , but haven't obtained more information about that. 
I have mounted /proc in the jail, but the same problem occurs. I have also tried to run strace from within the jail - same error.

I would really appreciate any hint about what might be missing. Without strace I'm kind of blind :)

P.S.: One thing I almost forgot. I can execute jls from within the jail and see some information about the other jailed hosts. Probably shouldn't be like that?

TIA,
Emil Filipov