"# Fatal error in , line 0" when trying to run Node app from Rsyslog

[alan-netmesh]

Version

22.6.0

Platform

Linux 5.14.0-427.16.1.el9_4.x86_64 nodejs/node#1 SMP PREEMPT_DYNAMIC Wed May 8 17:48:14 UTC 2024 x86_64 x86_64 x86_64 GNU/Linux

Subsystem

No response

What steps will reproduce the bug?

Not sure how to reproduce it, since I don't really understand the stack trace. My app it's intended to recieve a string from stdin, store that in a variable, strip some parts of it (with regex.test) and send a post request. If I run it from cli (i.e. cat myfile | node app.js) it works just fine.

How often does it reproduce? Is there a required condition?

It happens only and every single time that Rsyslog tries to run my (quite simple) Node app using omprog module.

What is the expected behavior? Why is that the expected behavior?

The expected behavior it's a console.log() inside my app.js that outputs the line received from stdin, or a message "Line didn't match regex", it's pretty much the only purpose of the app.

What do you see instead?

# Fatal error in , line 0
# Check failed: 12 == (*__errno_location ()).
#
#
#
#FailureMessage Object: 0x7ffeadf78580
----- Native stack trace -----

 1: 0x100d701  [/root/.nvm/versions/node/v22.6.0/bin/node]
 2: 0x28d98cb V8_Fatal(char const*, ...) [/root/.nvm/versions/node/v22.6.0/bin/node]
 3: 0x28e4a87 v8::base::OS::SetPermissions(void*, unsigned long, v8::base::OS::MemoryPermission) [/root/.nvm/versions/node/v22.6.0/bin/node]
 4: 0x14cd3d5 v8::internal::MemoryAllocator::SetPermissionsOnExecutableMemoryChunk(v8::internal::VirtualMemory*, unsigned long, unsigned long, unsigned long) [/root/.nvm/versions/node/v22.6.0/bin/node]
 5: 0x14cd6f1 v8::internal::MemoryAllocator::AllocateAlignedMemory(unsigned long, unsigned long, unsigned long, v8::internal::AllocationSpace, v8::internal::Executability, void*, v8::internal::VirtualMemory*) [/root/.nvm/versions/node/v22.6.0/bin/node]
 6: 0x14cd964 v8::internal::MemoryAllocator::AllocateUninitializedChunkAt(v8::internal::BaseSpace*, unsigned long, v8::internal::Executability, unsigned long, v8::internal::PageSize) [/root/.nvm/versions/node/v22.6.0/bin/node]
 7: 0x14cdb6c v8::internal::MemoryAllocator::AllocatePage(v8::internal::MemoryAllocator::AllocationMode, v8::internal::Space*, v8::internal::Executability) [/root/.nvm/versions/node/v22.6.0/bin/node]
 8: 0x14eb1b0 v8::internal::PagedSpaceBase::TryExpand(v8::internal::LocalHeap*, v8::internal::AllocationOrigin) [/root/.nvm/versions/node/v22.6.0/bin/node]
 9: 0x149a323 v8::internal::PagedSpaceAllocatorPolicy::RefillLab(int, v8::internal::AllocationOrigin) [/root/.nvm/versions/node/v22.6.0/bin/node]
10: 0x14984eb v8::internal::MainAllocator::AllocateRawSlow(int, v8::internal::AllocationAlignment, v8::internal::AllocationOrigin) [/root/.nvm/versions/node/v22.6.0/bin/node]
11: 0x14377e6 v8::internal::Factory::CodeBuilder::AllocateUninitializedInstructionStream(bool) [/root/.nvm/versions/node/v22.6.0/bin/node]
12: 0x144f419 v8::internal::Factory::CodeBuilder::BuildInternal(bool) [/root/.nvm/versions/node/v22.6.0/bin/node]
13: 0x19c5eb2 v8::internal::baseline::BaselineCompiler::Build(v8::internal::LocalIsolate*) [/root/.nvm/versions/node/v22.6.0/bin/node]
14: 0x1291dfa v8::internal::GenerateBaselineCode(v8::internal::Isolate*, v8::internal::Handle<v8::internal::SharedFunctionInfo>) [/root/.nvm/versions/node/v22.6.0/bin/node]
15: 0x12ef40b v8::internal::Compiler::CompileSharedWithBaseline(v8::internal::Isolate*, v8::internal::Handle<v8::internal::SharedFunctionInfo>, v8::internal::Compiler::ClearExceptionFlag, v8::internal::IsCompiledScope*) [/root/.nvm/versions/node/v22.6.0/bin/node]
16: 0x12ef6b2 v8::internal::Compiler::CompileBaseline(v8::internal::Isolate*, v8::internal::Handle<v8::internal::JSFunction>, v8::internal::Compiler::ClearExceptionFlag, v8::internal::IsCompiledScope*) [/root/.nvm/versions/node/v22.6.0/bin/node]
17: 0x19c334b v8::internal::baseline::BaselineBatchCompiler::CompileBatch(v8::internal::Handle<v8::internal::JSFunction>) [/root/.nvm/versions/node/v22.6.0/bin/node]
18: 0x13dda9f v8::internal::TieringManager::OnInterruptTick(v8::internal::Handle<v8::internal::JSFunction>, v8::internal::CodeKind) [/root/.nvm/versions/node/v22.6.0/bin/node]
19: 0x18971fb  [/root/.nvm/versions/node/v22.6.0/bin/node]
20: 0x1898e44 v8::internal::Runtime_BytecodeBudgetInterruptWithStackCheck_Ignition(int, unsigned long*, v8::internal::Isolate*) [/root/.nvm/versions/node/v22.6.0/bin/node]
21: 0x1f50576  [/root/.nvm/versions/node/v22.6.0/bin/node]

Additional information

It's a Rocky Linux 9 server, NodeJS installed using nvm (nvm installed with bash script, nothing out of the ordinary) and SELinux it's on permissive (at first I thought that it might be that)

Rsyslog version: rsyslogd: version 8.2310.0-4.el9
The os it's fully up to date, no extra repos apart from EPEL.

The exact same setup (Rsyslog + Omprog module + NodeJS APP) It's been running on a debian box for well over a year, the only changes are Node version and the underlying os, moving from Debian to RL9.

[avivkeller]

The expected behavior it's a console.log() inside my app.js that outputs the line received from stdin, or a message "Line didn't match regex", it's pretty much the only purpose of the app.

Can you provide a minimal reproducible example? One that doesn't rely on any dependencies or specific unnecessary functions?

[alan-netmesh]

The expected behavior it's a console.log() inside my app.js that outputs the line received from stdin, or a message "Line didn't match regex", it's pretty much the only purpose of the app.

Can you provide a minimal reproducible example? One that doesn't rely on any dependencies or specific unnecessary functions?

I can try slimming down the app (to the bare minimum, since it even uses ejs to parse an html email template and dotenv for parameters) and try to reproduce it, since it only happens when called from rsyslogd.
I'll take me an hour or so. I'll be back here with news, if it happens I'll attach the .js file.

EDIT: Right after submitting the issue, tried downgrading node to LTS (v20.16.0), same behavior.

[avivkeller]

My gut feeling says this may be an issue with a dependency or a system specific issue, but a slim reproduction without any dependencies would help to verify that

[alan-netmesh]

Okay, slimmed down the code to the bare minimum, even removing the axios post. (from 350 lines to 30!)
The only dependencies: minimist-lite and readline.

The original app did this: check arguments, if --stdin specified, use readline to read standard input, pass it into a function, check against 4 or 5 regex and keep the results in variables. Then use those variables to populate a json body and post it to another server (also node + express, which it should be next for this migration from debian to rl9)

The code it's far from optimal, I do this for hobby and also lacks lots of checks that the original app did, but works for reproducing it.
Usage: echo "My line to be matched" | node app.js --stdtin

The regex it's matching 3 numbers from 0 to 9 Hello World and the 3 numbers from 0 to 9 (since the original one its over 100 char long and made no sense to post here.

Works fine in a CLI using echo "222 Hello World 123" | node app.js --stdin but doesn't (same crash) if rsyslog invokes the same program.

Here is the code, also i've attached the JS with the extension changed to ZIP (its a plaintext file, not a real ZIP) if github messes the format.

var args = require('minimist-lite')(process.argv.slice(2));
const regexline = RegExp(/^[0-9]{3} Hello World [0-9]{3}$/);

const readline = require('readline');
const rl = readline.createInterface({
  input: process.stdin,
  output: process.stdout,
  terminal: false
});


if (!(args.stdin === undefined)){
  rl.on('line', (line) => {
      testLineAlan(line);
  });
  rl.once('close', () => {
  });
}


function testLineAlan(linealog){
  if (!(regexline.test(linealog))){
        // If this doesn't match, I'll leave with an error message.
        console.error("Doesn't match the regex, exiting...")
        process.exit()
  }else{
  console.log("Match RegEx: " + linealog);
  }
}

app-syslog-test.zip

[alan-netmesh]

I'm open to test anything if wanted, but if anyone wants to replicate it, here it's the basic configuration of rsyslog:

#Enable imudp and bind it to ruleset loglocal (only add the ruleset parameter, comes enabled by default on rhel rsyslog package)
module(load="imudp") # needs to be done just once
input(type="imudp" port="514" ruleset="loglocal")

# Enable omprog module
module(load="omprog")

# Create template for the syslog line format passed to the node app
template(name="templatealan"
         type="string"
         string="%$year%-%$month%-%$day% %timereported:8:25% -%msg%\r")

# Define ruleset and omprog call to node
ruleset(name="loglocal"){
    if $fromhost-ip == '10.10.10.10' and $msg startswith ' test-alan' then {
        action(type="omprog" binary="/root/.nvm/versions/node/v20.16.0/bin/node /opt/testapp/app.js --stdin" template="templatealan" output="/var/log/rsyslog-test/test-alan.log")
        stop
    }
    # Log everything else to a file (kinda catch)
    action(type="omfile" file="/var/log/rsyslog-test/log-total.log" template="templatealan")
    stop
}

I know this is not related to node at all, but I paste it here merely for context and if anyone wants to replicate it on the same way I'm doing it.

[avivkeller]

Works fine in a CLI using echo "222 Hello World 123" | node app.js --stdin but doesn't (same crash) if rsyslog invokes the same program.

To me, it seems this might be an issue with rsyslog or some other non-node program, but I'm happy to see what others think

[alan-netmesh]

Works fine in a CLI using echo "222 Hello World 123" | node app.js --stdin but doesn't (same crash) if rsyslog invokes the same program.

To me, it seems this might be an issue with rsyslog or some other non-node program, but I'm happy to see what others think

It's possible, but since the crash it's from node, I came here to try to understand what's happening.

On the other hand, with the same exact configuration if I make rsyslog pipe the log line to a shell script, it works great, so I don't really have anything to ask for help on rsyslog, they will tell me to kick rocks, lol.

I'm open for comments from anyone who has any ideas to try, since I don't have any clue what the stack trace means.

[avivkeller]

I would try and debug locally, but I know very little (borderline nothing) about rsyslog.

@nodejs/v8 might be able to help with the stack trace.

[skye-lopez]

Hello I am only somewhat familiar with rsyslog and omprog, and am wanting to reproduce this locally to assist you in debugging.

I want to make sure I understand the use case first:

• 1. You are using imudp capture syslog messages via UDP
• 2. If you recieve message on port 514 you call up omprog to run your node script with the log as stdin
• 3. And then whatever else you are going to do with that data (doesnt seem relevant to the bug)

Is there anyway you can give me a set of local commands I can use to replicate running this script?

I tried to simplify the /etc/rsyslog.conf to the following:

#Enable imudp and bind it to ruleset loglocal (only add the ruleset parameter, comes enabled by default on rhel rsyslog package)
module(load="imudp") # needs to be done just once
input(type="imudp" port="8899" ruleset="loglocal")

# Enable omprog module
module(load="omprog")

# Create template for the syslog line format passed to the node app
template(name="templatealan"
         type="string"
         string="%$year%-%$month%-%$day% %timereported:8:25% -%msg%\r")

# Define ruleset and omprog call to node
ruleset(name="loglocal"){
    action(type="omprog" binary="/usr/bin/node /home/a/node-bug-test/test.js --stdin" template="templatealan" output="/home/a/test/test.log")
    stop
}

Then run this to start netcat in UDP mode
nc -ul -p 8899

And then run this to send a message
echo "Hello World" | nc -u -w1 127.0.0.1 8899

Sadly nothing ended up happening at this point.

[avivkeller]

Could a member transfer this to nodejs/help?

[alan-netmesh]

I guess github didn't notify me vía email. Just saw all the activity.
@redyetidev Not really sure how it's "wrong repo" and moved to help, node it's crashing...

@skye-lopez Thanks your your time, you understood correctly, I'll write something to replicate asap, since on my test environment I'm sending test messages from a mikrotik router.

[avivkeller]

@redyetidev Not really sure how it's "wrong repo" and moved to help, node it's crashing...

nodejs/help is better for issues that behave as expected when executed normally compared to with other programs. If new evidence comes to light, it can always be moved back.

[alan-netmesh]

@redyetidev I tried reaching the v8 repo and seems to have issues disabled, where I can ask someone to explain to me that stack trace? I think that's the key to solving this.

@skye-lopez I was able to reproduce it using netcat, seems like syslog interprets the first word as the hostname and the second one as the programname.

echo "127.0.0.1 whatever,here test-alan: 123 Hello World 456" | nc -u -w1 127.0.0.1 514
Syslog will parse that as:
[2024-08-20 10:47:17] 127.0.0.1(127.0.0.1) >> whatever,here test-alan: 123 Hello World 456

being 127.0.0.1 the variable %hostname% and whatever,here %programname%
the test-alan: it's not mandatory, it's because I'm using it as a filter with $msg startswith ' test-alan'

With that, it invokes the node app and gives the same crash.
I'm redeploying everything on another clean VM, to discard any wrongdoings made with selinux or anything related to security (I think this VM was secured to meet NIST 800-53).

If this last thing it's the root cause, It won't be wasted time since this issue may help someone else.

[avivkeller]

V8 issues can be reported at https://issues.chromium.org/issues/wizard, but this isn't (hopefully) an issue with V8.

[alan-netmesh]

V8 issues can be reported at https://issues.chromium.org/issues/wizard, but this isn't (hopefully) an issue with V8.

I don't think it's an issue with V8, more like a permissions thing with this VM, but V8 shouldn't crash, instead catch the exception and give an error I think?

[alan-netmesh]

V8 issues can be reported at https://issues.chromium.org/issues/wizard, but this isn't (hopefully) an issue with V8.

I've got not so good news. Tried a 100% clean install of Rocky Linux 9, only did a dnf update, installed curl and nano, nvm and node and loaded the configs on rsyslogd.

It's still crashing. :(

I've opened an issue today morning on that link, no updates at all. Maybe there is anyone who we can tag that understands the stack trace?

#
# Fatal error in , line 0
# Check failed: 12 == (*__errno_location ()).
#
#
#
#FailureMessage Object: 0x7ffd2e65e110
----- Native stack trace -----

 1: 0x100d701  [/root/.nvm/versions/node/v22.6.0/bin/node]
 2: 0x28d98cb V8_Fatal(char const*, ...) [/root/.nvm/versions/node/v22.6.0/bin/node]
 3: 0x28e4a87 v8::base::OS::SetPermissions(void*, unsigned long, v8::base::OS::MemoryPermission) [/root/.nvm/versions/node/v22.6.0/bin/node]
 4: 0x14cd3d5 v8::internal::MemoryAllocator::SetPermissionsOnExecutableMemoryChunk(v8::internal::VirtualMemory*, unsigned long, unsigned long, unsigned long) [/root/.nvm/versions/node/v22.6.0/bin/node]
 5: 0x14cd6f1 v8::internal::MemoryAllocator::AllocateAlignedMemory(unsigned long, unsigned long, unsigned long, v8::internal::AllocationSpace, v8::internal::Executability, void*, v8::internal::VirtualMemory*) [/root/.nvm/versions/node/v22.6.0/bin/node]
 6: 0x14cd964 v8::internal::MemoryAllocator::AllocateUninitializedChunkAt(v8::internal::BaseSpace*, unsigned long, v8::internal::Executability, unsigned long, v8::internal::PageSize) [/root/.nvm/versions/node/v22.6.0/bin/node]
 7: 0x14cdb6c v8::internal::MemoryAllocator::AllocatePage(v8::internal::MemoryAllocator::AllocationMode, v8::internal::Space*, v8::internal::Executability) [/root/.nvm/versions/node/v22.6.0/bin/node]
 8: 0x14eb1b0 v8::internal::PagedSpaceBase::TryExpand(v8::internal::LocalHeap*, v8::internal::AllocationOrigin) [/root/.nvm/versions/node/v22.6.0/bin/node]
 9: 0x149a323 v8::internal::PagedSpaceAllocatorPolicy::RefillLab(int, v8::internal::AllocationOrigin) [/root/.nvm/versions/node/v22.6.0/bin/node]
10: 0x14984eb v8::internal::MainAllocator::AllocateRawSlow(int, v8::internal::AllocationAlignment, v8::internal::AllocationOrigin) [/root/.nvm/versions/node/v22.6.0/bin/node]
11: 0x14377e6 v8::internal::Factory::CodeBuilder::AllocateUninitializedInstructionStream(bool) [/root/.nvm/versions/node/v22.6.0/bin/node]
12: 0x144f419 v8::internal::Factory::CodeBuilder::BuildInternal(bool) [/root/.nvm/versions/node/v22.6.0/bin/node]
13: 0x19c5eb2 v8::internal::baseline::BaselineCompiler::Build(v8::internal::LocalIsolate*) [/root/.nvm/versions/node/v22.6.0/bin/node]
14: 0x1291dfa v8::internal::GenerateBaselineCode(v8::internal::Isolate*, v8::internal::Handle<v8::internal::SharedFunctionInfo>) [/root/.nvm/versions/node/v22.6.0/bin/node]
15: 0x12ef40b v8::internal::Compiler::CompileSharedWithBaseline(v8::internal::Isolate*, v8::internal::Handle<v8::internal::SharedFunctionInfo>, v8::internal::Compiler::ClearExceptionFlag, v8::internal::IsCompiledScope*) [/root/.nvm/versions/node/v22.6.0/bin/node]
16: 0x12ef6b2 v8::internal::Compiler::CompileBaseline(v8::internal::Isolate*, v8::internal::Handle<v8::internal::JSFunction>, v8::internal::Compiler::ClearExceptionFlag, v8::internal::IsCompiledScope*) [/root/.nvm/versions/node/v22.6.0/bin/node]
17: 0x19c334b v8::internal::baseline::BaselineBatchCompiler::CompileBatch(v8::internal::Handle<v8::internal::JSFunction>) [/root/.nvm/versions/node/v22.6.0/bin/node]
18: 0x13dda9f v8::internal::TieringManager::OnInterruptTick(v8::internal::Handle<v8::internal::JSFunction>, v8::internal::CodeKind) [/root/.nvm/versions/node/v22.6.0/bin/node]
19: 0x18971fb  [/root/.nvm/versions/node/v22.6.0/bin/node]
20: 0x1898e44 v8::internal::Runtime_BytecodeBudgetInterruptWithStackCheck_Ignition(int, unsigned long*, v8::internal::Isolate*) [/root/.nvm/versions/node/v22.6.0/bin/node]
21: 0x1f50576  [/root/.nvm/versions/node/v22.6.0/bin/node]

[skye-lopez]

I did not get any crash output with my config. Could you try to test with this slimmed down version of rsyslog? I will also try to replicate with yours @alan-netmesh

My feeling is this is a system or config issue... But I could be wrong.

Again just for context to reproduce:

Im on Ubuntu 24.04 LTS (native, not a vm) Node v18.19.1

my rsyslog.conf

module(load="imudp") # needs to be done just once
input(type="imudp" port="8899" ruleset="loglocal")

# Enable omprog module
module(load="omprog")

# Create template for the syslog line format passed to the node app
template(name="templatealan"
         type="string"
         string="%$year%-%$month%-%$day% %timereported:8:25% -%msg%\r")

# Define ruleset and omprog call to node
ruleset(name="loglocal"){
    action(type="omprog" binary="/usr/bin/node /home/a/node-bug-test/test.js --stdin" template="templatealan" output="/home/a/node-bug-test/test/test.log")
    stop
}

Started netcat:
nc -ul -p 8899

Ran your test string:
echo "127.0.0.1 whatever,here test-alan: 123 Hello World 456" | nc -u -w1 127.0.0.1 8899

My output:

➜  ~ nc -ul -p 8899
127.0.0.1 whatever,here test-alan: 123 Hello World 456

My test.js file:

var args = require('minimist-lite')(process.argv.slice(2));
const regexline = RegExp(/^[0-9]{3} Hello World [0-9]{3}$/);

const readline = require('readline');
const rl = readline.createInterface({
    input: process.stdin,
    output: process.stdout,
    terminal: false
});


if (!(args.stdin === undefined)) {
    rl.on('line', (line) => {
        testLineAlan(line);
    });
    rl.once('close', () => {
    });
}


function testLineAlan(linealog) {
    if (!(regexline.test(linealog))) {
        // If this doesn't match, I'll leave with an error message.
        console.error("Doesn't match the regex, exiting...")
        process.exit()
    } else {
        console.log("Match RegEx: " + linealog);
    }
}

[alan-netmesh]

@skye-lopez I'll try your config. But isn't about syslog or the node app. I've got an rsyslog instance with 300 or so filters on a ruleset, im quite familiar with it.

I bet it's a rsyslog and/or V8 problem ONLY on RL9, since the production it's Debian 11 for well over two years (uptime now it's on 400+ days and I've restarted that thing a couple of times)

Your output (stdout from omprog) on the file "[...]/test/test.log" should be "Match RegEx: 333 Hello World 111" or whatever numbers you put to match the regex.

[gireeshpunathil]

looking at

https://github.com/v8/v8/blob/42bad8a9787e1f85c3db37228ab6bdcf29e0bf07/src/base/platform/platform-posix.cc#L510

  int ret = mprotect(address, size, prot);
  // Setting permissions can fail if the limit of VMAs is exceeded.
  // Any failure that's not OOM likely indicates a bug in the caller (e.g.
  // using an invalid mapping) so attempt to catch that here to facilitate
  // debugging of these failures.
  if (ret != 0) CHECK_EQ(ENOMEM, errno);

looks like v8 anticipates only ENOMEM (12) as a potential failure from mprotect, and apparently it failed due to some other reason. unfortunately the assertion message did not carry what that error is.

so I would say v8 failed to foresee and handle a scenario where mprotect can fail for other reasons such as EACCES, EINVAL (as documented in https://man7.org/linux/man-pages/man2/mprotect.2.html)

[alan-netmesh]

looking at

https://github.com/v8/v8/blob/42bad8a9787e1f85c3db37228ab6bdcf29e0bf07/src/base/platform/platform-posix.cc#L510

  int ret = mprotect(address, size, prot);
  // Setting permissions can fail if the limit of VMAs is exceeded.
  // Any failure that's not OOM likely indicates a bug in the caller (e.g.
  // using an invalid mapping) so attempt to catch that here to facilitate
  // debugging of these failures.
  if (ret != 0) CHECK_EQ(ENOMEM, errno);

looks like v8 anticipates only ENOMEM (12) as a potential failure from mprotect, and apparently it failed due to some other reason. unfortunately the assertion message did not carry what that error is.

so I would say v8 failed to foresee and handle a scenario where mprotect can fail for other reasons such as EACCES, EINVAL (as documented in https://man7.org/linux/man-pages/man2/mprotect.2.html)

Hey! Hope you're having a good morning. Thanks very very much for your input, that's what I wanted from the start, someone that could help understanding what the stack trace meant.

I have some thoughts about this and I think it might come from the sandbox that rsyslog makes when launching a process. Since I tried to replicate this exact same setup on Debian as @skye-lopez did, and it doesn't crash.

Not really sure if it's worth to continue chasing the tail about this, but when launching the process as interactive mode with root permissions, it just works (to the day, I don't know the difference on how rsyslog launches on RHEL-based and Debian-based systems).

I'm open to comments and suggestions, if any of the resources I have on hand can help to nodejs.

[gireeshpunathil]

but when launching the process as interactive mode with root permissions, it just works

thanks @alan-netmesh for the pointers. then with reasonable confidence I can assert that mprotect failed with EACCESS.

can you run once with strace -f prepended to whatever command you used? like strace -f <node path> <other flags> <app>.. this will produce huge output, and all we care is the last few lines when it crashed. more specifically, the last line which contains the call to mprotect.

[alan-netmesh]

but when launching the process as interactive mode with root permissions, it just works

thanks @alan-netmesh for the pointers. then with reasonable confidence I can assert that mprotect failed with EACCESS.

can you run once with strace -f prepended to whatever command you used? like strace -f <node path> <other flags> <app>.. this will produce huge output, and all we care is the last few lines when it crashed. more specifically, the last line which contains the call to mprotect.

Hey Gireesh, thanks to you for the commitment on the issue.
I'm on it. I've been trying for the past hour to get strace to launch from the rsyslog config (to catch the error) and it's not giving any kind of output. (I've even tried the -o flag to redirect output to a file)

I've succedeed to launch it as root (not via rsyslog as interative w/root perms, literally as root user), but I don't think this trace helps, since the program runs just fine this way.
I'm attaching it, and I'll be back as soon as I can get strace to output something when launched via the rsyslog process.

strace-as-root.log

[gireeshpunathil]

ya - but as expected, all 50+ instances of mprotect returned 0, which means those all succeeded.

grep "mprotect" strace-as-root.log | grep " = "

we need the same for the failing context. looking at your script, I guess we need adjustments here for the redirection? for example, define --stdout and --stderr just like you defined --stdin?

    if $fromhost-ip == '127.0.0.1' and $msg startswith ' test-alan' then {
        action(type="omprog" binary="/root/.nvm/versions/node/v22.6.0/bin/node /opt/testapp/app.js --stdin" template="vpn2fa" output="/var/log/myfolder/test-alan.log")
    }

[alan-netmesh]

ya - but as expected, all 50+ instances of mprotect returned 0, which means those all succeeded.

grep "mprotect" strace-as-root.log | grep " = "

we need the same for the failing context. looking at your script, I guess we need adjustments here for the redirection? for example, define --stdout and --stderr just like you defined --stdin?

    if $fromhost-ip == '127.0.0.1' and $msg startswith ' test-alan' then {
        action(type="omprog" binary="/root/.nvm/versions/node/v22.6.0/bin/node /opt/testapp/app.js --stdin" template="vpn2fa" output="/var/log/myfolder/test-alan.log")
    }

--stdin in my script only makes the script read the message from stdin instead of --msg which would be a argument, so it doesn't do anything, that's there because rsyslog pipes the message instead of being on a variable.

I've tried this:

if $fromhost-ip == '127.0.0.1' and $msg startswith ' test-alan' then {
        action(type="omprog" binary="strace -f -o /tmp/strace-log.log /root/.nvm/versions/node/v22.6.0/bin/node /opt/testapp/app.js --stdin" template="vpn2fa" output="/var/log/myfolder/test-alan.log")
    }

Without success, on /var/log/messages it says something along the lines of
systemd-coredump[28616]: Process 28613 (strace) of user 0 dumped core.
with timestamp matching the time that rsyslog ran the command but no output anywhere.

It can't be very hard, I'm pretty sure im almost there. One or two cups of coffee and I'll be back with the strace.

[gireeshpunathil]

why don't you ask the rsyslog folks, if they know of a mechanism to trace system calls? I am unfamiliar with the tool, so have 0 ideas! (ofc, after you exhausted with your own attempts and coffee! :) )

[alan-netmesh]

why don't you ask the rsyslog folks, if they know of a mechanism to trace system calls? I am unfamiliar with the tool, so have 0 ideas! (ofc, after you exhausted with your own attempts and coffee! :) )

Got some news! Still cannot get any output from strace when launched from rsyslog, but I managed to find out that the culprit its MemoryDenyWriteExecute on the systemd file of rsyslog.

By default it comes yes, and on debian it comes undefined, that's why it doesn't crashes on Ubuntu and/or Debian.
I'm gonna ask about this and the strace on the rsyslog issue I have open, since they even wrote a blog post today with debugging procedures that I've followed and only found out that the env it's different, but that isn't the culprit.

[gireeshpunathil]

that makes sense! the doc says: The setting MemoryDenyWriteExecute will block the creation or alteration of a memory segment to become writable and executable as well. and obviously, with this setting none of the JS code will run v8, as it wants the code to be loaded into dynamic memory prior to execution.

so the obvious solution is to set the value to no.

if possible, lets still see if you can get strace output to see if mprotect throws EACCESS - for posterity!

[avivkeller]

Hey, some users in nodejs/node are reporting the same behavior, so maybe this issue should be transferred there?

[gireeshpunathil]

@alan-netmesh - is your issue resolved?

[alan-netmesh]

@alan-netmesh - is your issue resolved?

Hey Gireesh. I wasn't able to retrieve any strace output to report back then forgot about this.
The only way I could resove this, was indeed disabling MemoryDenyWriteExecute on Rsyslog systemd service file.

At least for me, we can mark this as solved.
Sorry for forgetting about the issue, and thanks everyone for the time invested on this.

Feel free to tag me on any issue related to rsyslog + node if someone needs help.