Loading of Node.js native module segfaults in Alpine 3.10 (works in 3.9)

Loading of Node.js native module segfaults in Alpine 3.10 (works in 3.9)

[Christof Marti]

[-- Attachment #1: Type: text/plain, Size: 1387 bytes --]

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`

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.

Thanks,

Christof


[-- Attachment #2: Type: text/html, Size: 5114 bytes --]

Re: Loading of Node.js native module segfaults in Alpine 3.10 (works in 3.9)

[Rich Felker]

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`
> 
> 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?

Rich

Re: Loading of Node.js native module segfaults in Alpine 3.10 (works in 3.9)

[Szabolcs Nagy]

* Rich Felker <dalias@libc.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
...

Re: Loading of Node.js native module segfaults in Alpine 3.10 (works in 3.9)

[A. Wilcox]

[-- Attachment #1.1: Type: text/plain, Size: 1010 bytes --]

On 06/09/2019 08:10, Christof Marti wrote:
> 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.


I am wondering if our patch (
https://code.foxkit.us/adelie/packages/blob/753435f2/user/node/stack-silliness.patch
) would fix this.  Is there any way you can try to build the Node
package with this patch applied locally?  Or, alternatively, you could
try to install our Node package directly (
https://distfiles.adelielinux.org/adelie/1.0-beta4/user/x86_64/node-10.16.3-r0.apk
- though I'm not sure this will install cleanly on an Alpine system ).

Best to you and yours,
--arw


-- 
A. Wilcox (awilfox)
Project Lead, Adélie Linux
https://www.adelielinux.org


[-- Attachment #2: OpenPGP digital signature --]
[-- Type: application/pgp-signature, Size: 833 bytes --]

Re: Loading of Node.js native module segfaults in Alpine 3.10 (works in 3.9)

[Christof Marti]

Thanks everyone for the quick replies!

I recompiled nodejs with the below patch and checked with the machines we saw the issue with that this indeed fixes it.

I'll check on the issue for aports if they can include it in their build (https://gitlab.alpinelinux.org/alpine/aports/issues/10767).

Thanks,

Christof


On 9/6/19, 6:06 PM, "A. Wilcox" <awilfox@adelielinux.org> wrote:

    On 06/09/2019 08:10, Christof Marti wrote:
    > 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.
    
    
    I am wondering if our patch (
    https://code.foxkit.us/adelie/packages/blob/753435f2/user/node/stack-silliness.patch
    ) would fix this.  Is there any way you can try to build the Node
    package with this patch applied locally?  Or, alternatively, you could
    try to install our Node package directly (
    https://distfiles.adelielinux.org/adelie/1.0-beta4/user/x86_64/node-10.16.3-r0.apk
    - though I'm not sure this will install cleanly on an Alpine system ).
    
    Best to you and yours,
    --arw
    
    
    -- 
    A. Wilcox (awilfox)
    Project Lead, Adélie Linux
    https://www.adelielinux.org