Follow @Openwall on Twitter for new release announcements and other news
[<prev] [next>] [<thread-prev] [thread-next>] [day] [month] [year] [list]
Message-ID: <20190906144420.GC22009@port70.net>
Date: Fri, 6 Sep 2019 16:44:20 +0200
From: Szabolcs Nagy <nsz@...t70.net>
To: musl@...ts.openwall.com
Cc: Christof Marti <chrmarti@...rosoft.com>
Subject: Re: Loading of Node.js native module segfaults in Alpine 3.10
 (works in 3.9)

* Rich Felker <dalias@...c.org> [2019-09-06 09:23:29 -0400]:
> On Fri, Sep 06, 2019 at 01:10:45PM +0000, Christof Marti wrote:
> > Hi everyone,
> > 
> > We have a Node.js native module that fails to load on Alpine 3.10
> > (musl-1.1.22-r3). It loads fine on Alpine 3.9 (musl-1.1.20-r4) and
> > other (Debian / CentOS base) Linux distros. I also specifically
> > tested with alpine:3.10 and debian:8 Docker images and Node.js
> > 10.16.3 to rule out differences between Node.js versions and the
> > Debian image does not show the problem.
> > 
> > The Dockerfile to reproduce is:
> > 
> > FROM alpine:3.10
> > RUN apk add g++ python make npm
> > RUN npm i spdlog
> > CMD /bin/sh -c "node -p 'require(\"spdlog\")'"
> > 
> > This is with the latest Docker for Windows and on Linux. At least
> > one Docker for Mac does not reproduce it, not sure what the
> > difference is with that.
> > 
> > I have built the Dockerfile for convenience: `docker run
> > chrmarti/alpine-spdlog-segfault`

if you report libc issues with a docker reproducer
it should be at least

docker run --privileged ...

because the default docker environment is not something
any linux libc can support (too many security hardening
and resource limiting false positives)

i tried your docker file with plain docker run and
i cannot reproduce the segfault, but my machine
is aarch64 and there are many moving components
here that may behave differently on aarch64.

> > 
> > The source of the spdlog node module is at:
> > https://github.com/Microsoft/node-spdlog
> > 
> > Removing line-by-line from the source suggests that as soon as the
> > wrapped library (spdlog itself) is linked in the loading in Node.js
> > fails. Loading the wrapped library in an executable outside of
> > Node.js did work.
> > 
> > I have filed an issue for Alpine, but it was suggested that I should
> > follow-up upstream:
> > https://gitlab.alpinelinux.org/alpine/aports/issues/10767
> > 
> > We couldn't establish the source of the problem with certainty. Any
> > help on tracking this down further is appreciated.
> 
> Have you checked with gdb, strace, or any other log/trace output to
> get an idea of the type/cause of crash? Is it possible that there are
> bad seccomp filters involved and this is just them trapping something?
> What type of operations is the spdlog module performing on load? Are
> there threads involved?

relevant part of the strace on aarch64:
(dlopen is marked with <<<<<<<<<<)

note: node uses multiple threads, uses its own statx etc
syscalls that may not be on the docker seccomp whitelist
on an old docker install, uses its own allocator with
MAP_NORESERVE and madvise MADV_FREE, etc, so there are lot
of fragile hacks outside of musl that may go wrong.

...
[pid     8] statx(AT_FDCWD, "/node_modules/spdlog/build/Release", AT_STATX_SYNC_AS_STAT|AT_SYMLINK_NOFOLLOW, STATX_ALL, {stx_mask=STATX_TYPE|STATX_MODE|STATX_NLINK|STATX_UID|
STATX_GID|STATX_MTIME|STATX_CTIME|STATX_INO|STATX_SIZE|STATX_BLOCKS|STATX_BTIME, stx_attributes=0, stx_mode=S_IFDIR|0755, stx_size=4096, ...}) = 0
[pid     8] statx(AT_FDCWD, "/node_modules/spdlog/build/Release/spdlog.node", AT_STATX_SYNC_AS_STAT|AT_SYMLINK_NOFOLLOW, STATX_ALL, {stx_mask=STATX_TYPE|STATX_MODE|STATX_NLIN
K|STATX_UID|STATX_GID|STATX_MTIME|STATX_CTIME|STATX_INO|STATX_SIZE|STATX_BLOCKS|STATX_BTIME, stx_attributes=0, stx_mode=S_IFREG|0755, stx_size=276912, ...}) = 0
<<<<<<<<<
[pid     8] openat(AT_FDCWD, "/node_modules/spdlog/build/Release/spdlog.node", O_RDONLY|O_LARGEFILE|O_CLOEXEC) = 18
[pid     8] fcntl(18, F_SETFD, FD_CLOEXEC) = 0
[pid     8] fstat(18, {st_mode=S_IFREG|0755, st_size=276912, ...}) = 0
[pid     8] read(18, "\177ELF\2\1\1\0\0\0\0\0\0\0\0\0\3\0\267\0\1\0\0\0\220\"\1\0\0\0\0\0"..., 960) = 960
[pid     8] mmap(NULL, 274432, PROT_READ|PROT_EXEC, MAP_PRIVATE, 18, 0) = 0xffffaab3d000
[pid     8] mmap(0xffffaab7d000, 12288, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_FIXED, 18, 0x30000) = 0xffffaab7d000
[pid     8] close(18)                   = 0
[pid     8] mprotect(0xffffaab7d000, 8192, PROT_READ) = 0
[pid     8] rt_sigprocmask(SIG_BLOCK, ~[RTMIN RT_1 RT_2], [], 8) = 0
[pid     8] membarrier(MEMBARRIER_CMD_PRIVATE_EXPEDITED, 0) = 0
[pid     8] rt_sigprocmask(SIG_SETMASK, [], NULL, 8) = 0
<<<<<<<<<<
[pid     8] mmap(0x2e800000, 1044480, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x2e800000
[pid     8] munmap(0x2e880000, 520192)  = 0
[pid     8] mprotect(0x2e800000, 524288, PROT_READ|PROT_WRITE) = 0
[pid     8] mmap(0x4cd00000, 1044480, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0xffffaaa3e000
[pid     8] munmap(0xffffaaa3e000, 270336) = 0
[pid     8] munmap(0xffffaab00000, 249856) = 0
[pid     8] mprotect(0xffffaaa80000, 524288, PROT_READ|PROT_WRITE) = 0
[pid     8] mmap(0x20780000, 1044480, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x20780000
[pid     8] munmap(0x20800000, 520192)  = 0
[pid     8] mprotect(0x20780000, 524288, PROT_READ|PROT_WRITE) = 0
[pid     8] mmap(0x5b800000, 1044480, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x5b800000
[pid     8] munmap(0x5b880000, 520192)  = 0
[pid     8] mprotect(0x5b800000, 524288, PROT_READ|PROT_WRITE) = 0
[pid     8] mmap(0x31b00000, 1044480, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x31b00000
[pid     8] munmap(0x31b80000, 520192)  = 0
[pid     8] mprotect(0x31b00000, 524288, PROT_READ|PROT_WRITE) = 0
[pid     8] futex(0xffffabc399c4, FUTEX_WAKE_PRIVATE, 1) = 1
[pid    12] <... futex resumed> )       = 0
[pid    12] mmap(0x46f00000, 1044480, PROT_NONE, MAP_PRIVATE|MAP_ANONYMOUS|MAP_NORESERVE, -1, 0) = 0x46f00000
[pid    12] munmap(0x46f80000, 520192)  = 0
[pid    12] mprotect(0x46f00000, 524288, PROT_READ|PROT_WRITE) = 0
[pid    12] futex(0xffffabc39874, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid     8] futex(0xffffabc39874, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid    12] <... futex resumed> )       = -1 EAGAIN (Resource temporarily unavailable)
[pid     8] <... futex resumed> )       = 0
[pid    12] futex(0xffffe8dafc34, FUTEX_WAIT_PRIVATE, 2147483664, NULL <unfinished ...>
[pid     8] futex(0xffffe8dafc34, FUTEX_WAKE_PRIVATE, 1 <unfinished ...>
[pid    12] <... futex resumed> )       = -1 EAGAIN (Resource temporarily unavailable)
[pid     8] <... futex resumed> )       = 0
[pid    12] futex(0xffffabc399c4, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid     8] futex(0xffffacc3f9c4, FUTEX_WAKE_PRIVATE, 1) = 1
[pid    10] <... futex resumed> )       = 0
[pid    10] futex(0xffffacc3f9c4, FUTEX_WAIT_PRIVATE, 2, NULL <unfinished ...>
[pid     8] getpid()                    = 8
[pid     8] madvise(0xaaaabf145000, 188416, MADV_DONTNEED) = 0
[pid     8] write(1, "{ version: '0.17.0',\n  setAsyncM"..., 276) = 276
[pid     8] epoll_ctl(3, EPOLL_CTL_DEL, 1, 0xffffe8db1ed8) = -1 ENOENT (No such file or directory)
[pid     8] epoll_ctl(3, EPOLL_CTL_DEL, 2, 0xffffe8db1ed8) = -1 ENOENT (No such file or directory)
[pid     8] epoll_ctl(3, EPOLL_CTL_ADD, 6, {EPOLLIN, {u32=6, u64=6}}) = 0
[pid     8] epoll_ctl(3, EPOLL_CTL_ADD, 8, {EPOLLIN, {u32=8, u64=8}}) = 0
[pid     8] epoll_pwait(3, [], 1024, 0, NULL, 8) = 0
[pid     8] mprotect(0x5b800000, 524288, PROT_NONE) = 0
[pid     8] madvise(0x5b800000, 524288, MADV_FREE) = 0
...

Powered by blists - more mailing lists

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