Openwall GNU/*/Linux - a small security-enhanced Linux distro for servers
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Date: Sat, 8 Feb 2020 10:45:10 +0300
From: Alexander Scherbatiy <alexander.scherbatiy@...l-sw.com>
To: musl@...ts.openwall.com
Subject: Re: fopen with "e" mode to close file descriptor in exec... functions

Below are steps to reproduce it in docker, logs from docker and strace log.

> docker run --rm -it alpine:3.11.3 ash
> apk add gcc
> apk add libc-dev
Copy the posix_spawn_sample.c code below (note it uses "ash" in 'char
*argv[] = {"ash", ,,,}' for posix_spawn on Alpine Linux )

> gcc -o posix_spawn_sample posix_spawn_sample.c
> ./posix_spawn_sample

--- output ---
/ # ./posix_spawn_sample
Child pid: 17
PID=17
1 /bin/busybox /dev/pts/0
1 /bin/busybox /dev/pts/0
1 /bin/busybox /dev/pts/0
1 /bin/busybox /dev/tty
16 /posix_spawn_sample /dev/pts/0
16 /posix_spawn_sample /dev/pts/0
16 /posix_spawn_sample /dev/pts/0
16 /posix_spawn_sample /test.log
----------------

Note that "test.log" file is listed by "lsof -p PID" command.

----------  posix_spawn_sample.c ----------
#include <stdlib.h>
#include <stdio.h>
#include <string.h>

#include <unistd.h>
#include <spawn.h>
#include <sys/wait.h>

extern char **environ;

int main()
{
    FILE* file = fopen("test.log", "ae");
    fprintf(file, "test line\n");

    pid_t pid;
    // use "ash" for Alpine Linux and "bash" for Ubuntu
    char *argv[] = {"ash", "-c", "echo PID=$$ && lsof -p $$", NULL};
    int status = posix_spawn(&pid, "/bin/sh", NULL, NULL, argv, environ);
    printf("Child pid: %i\n", pid);
    waitpid(pid, &status, 0);

    fclose(file);
    return 0;
}
--------------------------

The full output step by step:
--------------------------------------
> docker run --rm -it alpine:3.11.3 ash
/ # apk add gcc
fetch http://dl-cdn.alpinelinux.org/alpine/v3.11/main/x86_64/APKINDEX.tar.gz
fetch
http://dl-cdn.alpinelinux.org/alpine/v3.11/community/x86_64/APKINDEX.tar.gz
(1/10) Installing libgcc (9.2.0-r3)
(2/10) Installing libstdc++ (9.2.0-r3)
(3/10) Installing binutils (2.33.1-r0)
(4/10) Installing gmp (6.1.2-r1)
(5/10) Installing isl (0.18-r0)
(6/10) Installing libgomp (9.2.0-r3)
(7/10) Installing libatomic (9.2.0-r3)
(8/10) Installing mpfr4 (4.0.2-r1)
(9/10) Installing mpc1 (1.1.0-r1)
(10/10) Installing gcc (9.2.0-r3)
Executing busybox-1.31.1-r9.trigger
OK: 101 MiB in 24 packages
/ # apk add libc-dev
(1/2) Installing musl-dev (1.1.24-r0)
(2/2) Installing libc-dev (0.7.2-r0)
OK: 111 MiB in 26 packages
/ #  gcc -o posix_spawn_sample posix_spawn_sample.c
/ # ./posix_spawn_sample
Child pid: 17
PID=17
1 /bin/busybox /dev/pts/0
1 /bin/busybox /dev/pts/0
1 /bin/busybox /dev/pts/0
1 /bin/busybox /dev/tty
16 /posix_spawn_sample /dev/pts/0
16 /posix_spawn_sample /dev/pts/0
16 /posix_spawn_sample /dev/pts/0
16 /posix_spawn_sample /test.log
--------------------------------------

strace log
--------------------------------------
/ # strace -f ./posix_spawn_sample
execve("./posix_spawn_sample", ["./posix_spawn_sample"], 0x7ffd951eb318 /*
6 vars */) = 0
arch_prctl(ARCH_SET_FS, 0x7f0fa33d6d48) = 0
set_tid_address(0x7f0fa33d731c)         = 31
mprotect(0x7f0fa33d3000, 4096, PROT_READ) = 0
mprotect(0x55e26cf7b000, 4096, PROT_READ) = 0
open("test.log", O_WRONLY|O_CREAT|O_APPEND|O_CLOEXEC, 0666) = 3
fcntl(3, F_SETFD, FD_CLOEXEC)           = 0
fcntl(3, F_SETFD, FD_CLOEXEC)           = 0
fcntl(3, F_GETFL)                       = 0x8401 (flags
O_WRONLY|O_APPEND|O_LARGEFILE)
ioctl(3, TIOCGWINSZ, 0x7ffd87e838a8)    = -1 ENOTTY (Not a tty)
pipe2([4, 5], O_CLOEXEC)                = 0
rt_sigprocmask(SIG_BLOCK, ~[], [], 8)   = 0
clone(child_stack=0x7ffd87e838b8, flags=CLONE_VM|CLONE_VFORK|SIGCHLDstrace:
Process 32 attached
 <unfinished ...>
[pid    32] close(4)                    = 0
[pid    32] fcntl(5, F_SETFD, FD_CLOEXEC) = 0
[pid    32] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid    32] execve("/bin/sh", ["ash", "-c", "echo PID=$$ && lsof -p $$"],
0x7ffd87e83998 /* 6 vars */ <unfinished ...>
[pid    31] <... clone resumed>)        = 32
[pid    32] <... execve resumed>)       = 0
[pid    31] close(5 <unfinished ...>
[pid    32] arch_prctl(ARCH_SET_FS, 0x7f1a19d9ed48 <unfinished ...>
[pid    31] <... close resumed>)        = 0
[pid    31] read(4,  <unfinished ...>
[pid    32] <... arch_prctl resumed>)   = 0
[pid    31] <... read resumed>"", 4)    = 0
[pid    32] set_tid_address(0x7f1a19d9f31c <unfinished ...>
[pid    31] close(4 <unfinished ...>
[pid    32] <... set_tid_address resumed>) = 32
[pid    31] <... close resumed>)        = 0
[pid    32] mprotect(0x7f1a19d9b000, 4096, PROT_READ <unfinished ...>
[pid    31] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
[pid    32] <... mprotect resumed>)     = 0
[pid    31] ioctl(1, TIOCGWINSZ, {ws_row=40, ws_col=155, ws_xpixel=0,
ws_ypixel=0}) = 0
[pid    32] mprotect(0x556eae13a000, 16384, PROT_READ <unfinished ...>
[pid    31] writev(1, [{iov_base="Child pid: 32", iov_len=13},
{iov_base="\n", iov_len=1}], 2 <unfinished ...>
[pid    32] <... mprotect resumed>)     = 0Child pid: 32

[pid    31] <... writev resumed>)       = 14
[pid    31] wait4(32,  <unfinished ...>
[pid    32] getuid()                    = 0
[pid    32] getpid()                    = 32
[pid    32] rt_sigprocmask(SIG_UNBLOCK, [RT_1 RT_2], NULL, 8) = 0
[pid    32] rt_sigaction(SIGCHLD, {sa_handler=0x556eae0b9dfc,
sa_mask=~[RTMIN RT_1 RT_2], sa_flags=SA_RESTORER,
sa_restorer=0x7f1a19d500d4}, NULL, 8) = 0
[pid    32] rt_sigaction(SIGHUP, {sa_handler=SIG_DFL, sa_mask=[],
sa_flags=SA_RESTORER|SA_RESTART, sa_restorer=0x7f1a19d500d4},
{sa_handler=SIG_DFL, sa_mask=[], sa_flags=0}, 8) = 0
[pid    32] getppid()                   = 31
[pid    32] stat("/", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid    32] stat(".", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
[pid    32] rt_sigaction(SIGINT, NULL, {sa_handler=SIG_DFL, sa_mask=[],
sa_flags=0}, 8) = 0
[pid    32] rt_sigaction(SIGINT, {sa_handler=0x556eae0b9dfc,
sa_mask=~[RTMIN RT_1 RT_2], sa_flags=SA_RESTORER,
sa_restorer=0x7f1a19d500d4}, NULL, 8) = 0
[pid    32] rt_sigaction(SIGQUIT, NULL, {sa_handler=SIG_DFL, sa_mask=[],
sa_flags=0}, 8) = 0
[pid    32] rt_sigaction(SIGQUIT, {sa_handler=SIG_IGN, sa_mask=~[RTMIN RT_1
RT_2], sa_flags=SA_RESTORER, sa_restorer=0x7f1a19d500d4}, NULL, 8) = 0
[pid    32] rt_sigaction(SIGTERM, NULL, {sa_handler=SIG_DFL, sa_mask=[],
sa_flags=0}, 8) = 0
[pid    32] wait4(-1, 0x7fff4e3ea22c, WNOHANG, NULL) = -1 ECHILD (No child
process)
[pid    32] write(1, "PID=32\n", 7PID=32
)     = 7
[pid    32] stat("/usr/local/sbin/lsof", 0x7fff4e3ea170) = -1 ENOENT (No
such file or directory)
[pid    32] stat("/usr/local/bin/lsof", 0x7fff4e3ea170) = -1 ENOENT (No
such file or directory)
[pid    32] stat("/usr/sbin/lsof", 0x7fff4e3ea170) = -1 ENOENT (No such
file or directory)
[pid    32] stat("/usr/bin/lsof", {st_mode=S_IFREG|0755, st_size=841288,
...}) = 0
[pid    32] brk(NULL)                   = 0x556eaf7c5000
[pid    32] brk(0x556eaf7c6000)         = 0x556eaf7c6000
[pid    32] execve("/usr/bin/lsof", ["lsof", "-p", "32"], 0x556eae13ed80 /*
6 vars */) = 0
[pid    32] arch_prctl(ARCH_SET_FS, 0x7fe42bc41d48) = 0
[pid    32] set_tid_address(0x7fe42bc4231c) = 32
[pid    32] mprotect(0x7fe42bc3e000, 4096, PROT_READ) = 0
[pid    32] mprotect(0x55d56c79b000, 16384, PROT_READ) = 0
[pid    32] getuid()                    = 0
[pid    32] open("/proc", O_RDONLY|O_CLOEXEC|O_DIRECTORY) = 3
[pid    32] fcntl(3, F_SETFD, FD_CLOEXEC) = 0
[pid    32] getdents64(3, /* 67 entries */, 2048) = 1984
[pid    32] readlink("/proc/1/exe", "/bin/busybox", 80) = 12
[pid    32] getpid()                    = 32
[pid    32] open("/proc/1/fd/", O_RDONLY|O_CLOEXEC|O_DIRECTORY) = 4
[pid    32] fcntl(4, F_SETFD, FD_CLOEXEC) = 0
[pid    32] brk(NULL)                   = 0x55d56dac0000
[pid    32] brk(0x55d56dac1000)         = 0x55d56dac1000
[pid    32] getdents64(4, /* 6 entries */, 2048) = 144
[pid    32] readlink("/proc/1/fd/0", "/dev/pts/0", 80) = 10
[pid    32] ioctl(1, TIOCGWINSZ, {ws_row=40, ws_col=155, ws_xpixel=0,
ws_ypixel=0}) = 0
[pid    32] writev(1, [{iov_base="1\t/bin/busybox\t/dev/pts/0",
iov_len=25}, {iov_base="\n", iov_len=1}], 21 /bin/busybox /dev/pts/0
) = 26
[pid    32] readlink("/proc/1/fd/1", "/dev/pts/0", 80) = 10
[pid    32] writev(1, [{iov_base="1\t/bin/busybox\t/dev/pts/0",
iov_len=25}, {iov_base="\n", iov_len=1}], 21 /bin/busybox /dev/pts/0
) = 26
[pid    32] readlink("/proc/1/fd/2", "/dev/pts/0", 80) = 10
[pid    32] writev(1, [{iov_base="1\t/bin/busybox\t/dev/pts/0",
iov_len=25}, {iov_base="\n", iov_len=1}], 21 /bin/busybox /dev/pts/0
) = 26
[pid    32] readlink("/proc/1/fd/10", "/dev/tty", 80) = 8
[pid    32] writev(1, [{iov_base="1\t/bin/busybox\t/dev/tty", iov_len=23},
{iov_base="\n", iov_len=1}], 21 /bin/busybox /dev/tty
) = 24
[pid    32] getdents64(4, /* 0 entries */, 2048) = 0
[pid    32] close(4)                    = 0
[pid    32] readlink("/proc/28/exe", "/usr/bin/strace", 80) = 15
[pid    32] getpid()                    = 32
[pid    32] open("/proc/28/fd/", O_RDONLY|O_CLOEXEC|O_DIRECTORY) = 4
[pid    32] fcntl(4, F_SETFD, FD_CLOEXEC) = 0
[pid    32] getdents64(4, /* 5 entries */, 2048) = 120
[pid    32] readlink("/proc/28/fd/0", "pipe:[89317]", 80) = 12
[pid    32] writev(1, [{iov_base="28\t/usr/bin/strace\tpipe:[89317]",
iov_len=31}, {iov_base="\n", iov_len=1}], 228 /usr/bin/strace pipe:[89317]
) = 32
[pid    32] readlink("/proc/28/fd/1", "pipe:[89318]", 80) = 12
[pid    32] writev(1, [{iov_base="28\t/usr/bin/strace\tpipe:[89318]",
iov_len=31}, {iov_base="\n", iov_len=1}], 228 /usr/bin/strace pipe:[89318]
) = 32
[pid    32] readlink("/proc/28/fd/2", "/dev/pts/0", 80) = 10
[pid    32] writev(1, [{iov_base="28\t/usr/bin/strace\t/dev/pts/0",
iov_len=29}, {iov_base="\n", iov_len=1}], 228 /usr/bin/strace /dev/pts/0
) = 30
[pid    32] getdents64(4, /* 0 entries */, 2048) = 0
[pid    32] close(4)                    = 0
[pid    32] readlink("/proc/31/exe", "/posix_spawn_sample", 80) = 19
[pid    32] getpid()                    = 32
[pid    32] open("/proc/31/fd/", O_RDONLY|O_CLOEXEC|O_DIRECTORY) = 4
[pid    32] fcntl(4, F_SETFD, FD_CLOEXEC) = 0
[pid    32] getdents64(4, /* 6 entries */, 2048) = 144
[pid    32] readlink("/proc/31/fd/0", "/dev/pts/0", 80) = 10
[pid    32] writev(1, [{iov_base="31\t/posix_spawn_sample\t/dev/pts/"...,
iov_len=33}, {iov_base="\n", iov_len=1}], 231 /posix_spawn_sample /dev/pts/0
) = 34
[pid    32] readlink("/proc/31/fd/1", "/dev/pts/0", 80) = 10
[pid    32] writev(1, [{iov_base="31\t/posix_spawn_sample\t/dev/pts/"...,
iov_len=33}, {iov_base="\n", iov_len=1}], 231 /posix_spawn_sample /dev/pts/0
) = 34
[pid    32] readlink("/proc/31/fd/2", "/dev/pts/0", 80) = 10
[pid    32] writev(1, [{iov_base="31\t/posix_spawn_sample\t/dev/pts/"...,
iov_len=33}, {iov_base="\n", iov_len=1}], 231 /posix_spawn_sample /dev/pts/0
) = 34
[pid    32] readlink("/proc/31/fd/3", "/test.log", 80) = 9
[pid    32] writev(1, [{iov_base="31\t/posix_spawn_sample\t/test.log",
iov_len=32}, {iov_base="\n", iov_len=1}], 231 /posix_spawn_sample /test.log
) = 33
[pid    32] getdents64(4, /* 0 entries */, 2048) = 0
[pid    32] close(4)                    = 0
[pid    32] readlink("/proc/32/exe", "/bin/busybox", 80) = 12
[pid    32] getpid()                    = 32
[pid    32] getdents64(3, /* 0 entries */, 2048) = 0
[pid    32] close(3)                    = 0
[pid    32] exit_group(0)               = ?
[pid    32] +++ exited with 0 +++
<... wait4 resumed>[{WIFEXITED(s) && WEXITSTATUS(s) == 0}], 0, NULL) = 32
--- SIGCHLD {si_signo=SIGCHLD, si_code=CLD_EXITED, si_pid=32, si_uid=0,
si_status=0, si_utime=0, si_stime=0} ---
writev(3, [{iov_base="test line\n", iov_len=10}, {iov_base=NULL,
iov_len=0}], 2) = 10
close(3)                                = 0
exit_group(0)                           = ?
+++ exited with 0 +++
--------------------------------------

Thanks,
Alexander.


On Sat, Feb 8, 2020 at 12:03 AM Rich Felker <dalias@...c.org> wrote:

> On Fri, Feb 07, 2020 at 09:22:01PM +0300, Alexander Scherbatiy wrote:
> > Hello,
> >
> > Below is a simple program without any errors handling that uses
> > fopen with "ae" mode to open a "test.log" file with append access
> > and call posix_spawn to create a child process and list all open files
> for
> > the child process.
> >
> > The program output shows that the child process has "test.log" file as
> open.
> > I used docker with Alpine Linux 3.11.3 (musl libc x86_64 1.1.24).
> > Is it an expected behaviour for Alpine Linux?
> >
> > The same program on my Ubuntu 19.10 (with "ash" changed to "bash") shows
> > that
> > the child process doesn't have  "test.log" file as open.
> >
> > Thanks,
> > Alexander.
> >
> > ----------  posix_spawn_sample.c ----------
> > #include <stdlib.h>
> > #include <stdio.h>
> > #include <string.h>
> >
> > #include <unistd.h>
> > #include <spawn.h>
> > #include <sys/wait.h>
> >
> > extern char **environ;
> >
> > int main()
> > {
> >     FILE* file = fopen("test.log", "ae");
> >     fprintf(file, "test line\n");
> >
> >     pid_t pid;
> >     char *argv[] = {"bash", "-c", "echo PID=$$ && lsof -p $$", NULL};
> >     int status = posix_spawn(&pid, "/bin/sh", NULL, NULL, argv, environ);
> >     printf("Child pid: %i\n", pid);
> >     waitpid(pid, &status, 0);
> >
> >     fclose(file);
> >     return 0;
> > }
> > --------------------------
>
> I can't reproduce this. I had to change /bin/sh to /bin/bash to be
> able to run the test at all, and the lsof I have (busybox) doesn't
> support -p, but I can't see any indication that the child has the log
> file open. I also tried changing it to run "ls -l /proc/$$/fd" in the
> child, and a fd 3 shows up there but prints an error because fd 3 is
> the directory fd for listing /proc/$$/fd and it's closed before trying
> to stat it -- apparently ash execs ls rather than running it as a
> child. Indeed adding "; echo" makes that go away.
>
> If you're still having the problem, could you attach a log of running
> your test under "strace -f"?
>
> Rich
>

Content of type "text/html" skipped

Powered by blists - more mailing lists

Your e-mail address:

Confused about mailing lists and their use? Read about mailing lists on Wikipedia and check out these guidelines on proper formatting of your messages.