isolate-vm silently crashing with a nested object

sanpj2292 commented 2 years ago

Hi team,

This is a developer from Rudderstack. We are using isolated-vm to run user-transformations(3rd party functions defined by the users). Recently we encountered an issue when a user is sending an event with a nested property that keeps on repeating itself

{
  ...,
  properties: {
    ...,
    properties: {
      ...,
      properties: {
        ...,
      }
    }
  }
}

When the code comes into this line, the service simply crashes without the error getting caught.

Observations

When the above mentioned nested payload is more than 1MB the crash is being seen but when the payload is < 1MB no crash happened.
The crash is happening in the docker container only
We tested the nested payload which had a size of 5.3MB by running the service locally surprisingly no crash was seen
When we used the 5.3MB'ed nested payload by running the service in Docker, a silent crash happened

What we need ?

We need your help in concluding about why this issue is happening
We'd really appreciate if there is some mechanism of catching this sort of error. If you guys can provide a mechanism such exceptions be caught through try-catch blocks in Javascript, we'll handle such exceptions in a way we would want to

Note : Attachments of payloads which are not crashing and those that are crashing is provided in the Attachments section

Code References

(IVM initialization code)[https://github.com/rudderlabs/rudder-transformer/blob/master/util/ivmFactory.js#L23]
(Dockerfile)[https://github.com/rudderlabs/rudder-transformer/blob/master/Dockerfile]

Attachments

Passing_nested_payload.json.txt Crash_nested_payload.json.txt

laverdet commented 2 years ago

What is the exit code of the process? If it's 0 this is often caused by an abandoned promise

if you're using a memoryLimit of <128 you might also run into issues.

If you can put together a reproduction that would be helpful.

sanpj2292 commented 2 years ago

What is the exit code of the process? If it's 0 this is often caused by an abandoned promise

When we tested with Crash_nested_payload.json.txt, the docker is exiting with exit code 0. We checked which promise is being abandoned, it seems like this line is that abandoned promise We're unable to find out why would that be. Can you help us understand it ?

if you're using a memoryLimit of <128 you might also run into issues.

ivm is being created here and we see that it is being created with a memory limit of 128 only

If you can put together a reproduction that would be helpful.

Steps to Reproduce:

Clone the repo rudder-transformer
Run the service in a docker container
Use Crash_nested_payload.json.txt & send a request to :9091/customTransform

Notes

Convert the crash nested payload text into a json by renaming the file
We used a tool known as (httpie)[https://httpie.io/] to send request to the endpoint 9091:/customTransform

Let me know if you need anymore details

laverdet commented 2 years ago

I tried to start your service via Docker by running the command included in the readme: docker-compose up transformer-no-func. It looks like python is missing in your image

I received this output:

-> % docker-compose up transformer-no-func
Creating network "rudder-transformer_default" with the default driver
Building transformer-no-func
[+] Building 11.2s (9/10)                                                       
 => [internal] load build definition from Dockerfile-no-func               0.0s
 => => transferring dockerfile: 219B                                       0.0s
 => [internal] load .dockerignore                                          0.0s
 => => transferring context: 153B                                          0.0s
 => [internal] load metadata for docker.io/library/node:10.16.0-alpine     1.3s
 => [1/6] FROM docker.io/library/node:10.16.0-alpine@sha256:07897ec27318d  1.5s
 => => resolve docker.io/library/node:10.16.0-alpine@sha256:07897ec27318d  0.0s
 => => sha256:b09a182c47e8fe10485c6004679511c185b1d7c69 21.58MB / 21.58MB  0.6s
 => => sha256:39d61d2ed87191c75ea7d607157d6412816da2762b2 1.34MB / 1.34MB  0.4s
 => => sha256:07897ec27318d8e43cfc6b1762e7a28ed01479ba492 1.42kB / 1.42kB  0.0s
 => => sha256:6467efe6481aace0c317f144079c1a321b91375a828 1.16kB / 1.16kB  0.0s
 => => sha256:8e0eeb0a11b3a91cc1d91b5ef637edd153a64a3792e 5.66kB / 5.66kB  0.0s
 => => sha256:0362ad1dd800a9d92f8982fa28f173f912026615383 2.69MB / 2.69MB  0.3s
 => => extracting sha256:0362ad1dd800a9d92f8982fa28f173f9120266153830f990  0.2s
 => => sha256:b4e2115e274ad73e48777b4d8523035a0b61c0a7f6c8391 280B / 280B  0.4s
 => => extracting sha256:b09a182c47e8fe10485c6004679511c185b1d7c6984dcc44  0.7s
 => => extracting sha256:39d61d2ed87191c75ea7d607157d6412816da2762b27b51e  0.1s
 => => extracting sha256:b4e2115e274ad73e48777b4d8523035a0b61c0a7f6c8391e  0.0s
 => [internal] load build context                                          0.4s
 => => transferring context: 7.34MB                                        0.4s
 => [2/6] WORKDIR /app                                                     0.1s
 => [3/6] COPY package*.json ./                                            0.0s
 => [4/6] COPY build.js ./                                                 0.0s
 => ERROR [5/6] RUN npm install --unsafe-perm                              8.1s
------
 > [5/6] RUN npm install --unsafe-perm:
#9 0.387 npm WARN read-shrinkwrap This version of npm is compatible with lockfileVersion@1, but package-lock.json was generated for lockfileVersion@2. I'll try to do my best with it!
#9 7.438 
#9 7.438 > dtrace-provider@0.8.8 install /app/node_modules/dtrace-provider
#9 7.438 > node-gyp rebuild || node suppress-error.js
#9 7.438 
#9 7.508 gyp ERR! configure error 
#9 7.508 gyp ERR! stack Error: Can't find Python executable "python", you can set the PYTHON env variable.
#9 7.508 gyp ERR! stack     at PythonFinder.failNoPython (/usr/local/lib/node_modules/npm/node_modules/node-gyp/lib/configure.js:484:19)
#9 7.508 gyp ERR! stack     at PythonFinder.<anonymous> (/usr/local/lib/node_modules/npm/node_modules/node-gyp/lib/configure.js:406:16)
#9 7.508 gyp ERR! stack     at F (/usr/local/lib/node_modules/npm/node_modules/which/which.js:68:16)
#9 7.508 gyp ERR! stack     at E (/usr/local/lib/node_modules/npm/node_modules/which/which.js:80:29)
#9 7.508 gyp ERR! stack     at /usr/local/lib/node_modules/npm/node_modules/which/which.js:89:16
#9 7.508 gyp ERR! stack     at /usr/local/lib/node_modules/npm/node_modules/isexe/index.js:42:5
#9 7.508 gyp ERR! stack     at /usr/local/lib/node_modules/npm/node_modules/isexe/mode.js:8:5
#9 7.508 gyp ERR! stack     at FSReqWrap.oncomplete (fs.js:153:21)
#9 7.508 gyp ERR! System Linux 5.10.47-linuxkit
#9 7.509 gyp ERR! command "/usr/local/bin/node" "/usr/local/lib/node_modules/npm/node_modules/node-gyp/bin/node-gyp.js" "rebuild"
#9 7.509 gyp ERR! cwd /app/node_modules/dtrace-provider
#9 7.509 gyp ERR! node -v v10.16.0
#9 7.509 gyp ERR! node-gyp -v v3.8.0
#9 7.509 gyp ERR! not ok 
#9 7.564 
#9 7.564 > heapdump@0.3.15 install /app/node_modules/heapdump
#9 7.564 > node-gyp rebuild
#9 7.564 
#9 7.630 gyp ERR! configure error 
#9 7.631 gyp ERR! stack Error: Can't find Python executable "python", you can set the PYTHON env variable.
#9 7.631 gyp ERR! stack     at PythonFinder.failNoPython (/usr/local/lib/node_modules/npm/node_modules/node-gyp/lib/configure.js:484:19)
#9 7.631 gyp ERR! stack     at PythonFinder.<anonymous> (/usr/local/lib/node_modules/npm/node_modules/node-gyp/lib/configure.js:406:16)
#9 7.631 gyp ERR! stack     at F (/usr/local/lib/node_modules/npm/node_modules/which/which.js:68:16)
#9 7.632 gyp ERR! stack     at E (/usr/local/lib/node_modules/npm/node_modules/which/which.js:80:29)
#9 7.632 gyp ERR! stack     at /usr/local/lib/node_modules/npm/node_modules/which/which.js:89:16
#9 7.632 gyp ERR! stack     at /usr/local/lib/node_modules/npm/node_modules/isexe/index.js:42:5
#9 7.632 gyp ERR! stack     at /usr/local/lib/node_modules/npm/node_modules/isexe/mode.js:8:5
#9 7.632 gyp ERR! stack     at FSReqWrap.oncomplete (fs.js:153:21)
#9 7.633 gyp ERR! System Linux 5.10.47-linuxkit
#9 7.633 gyp ERR! command "/usr/local/bin/node" "/usr/local/lib/node_modules/npm/node_modules/node-gyp/bin/node-gyp.js" "rebuild"
#9 7.633 gyp ERR! cwd /app/node_modules/heapdump
#9 7.633 gyp ERR! node -v v10.16.0
#9 7.633 gyp ERR! node-gyp -v v3.8.0
#9 7.634 gyp ERR! not ok 
#9 7.799 npm WARN rudder-transformer@0.1.5-rc.0 No description
#9 7.799 npm WARN The package minimist is included as both a dev and production dependency.
#9 7.799 npm WARN optional SKIPPING OPTIONAL DEPENDENCY: fsevents@2.1.3 (node_modules/fsevents):
#9 7.800 npm WARN notsup SKIPPING OPTIONAL DEPENDENCY: Unsupported platform for fsevents@2.1.3: wanted {"os":"darwin","arch":"any"} (current: {"os":"linux","arch":"arm64"})
#9 7.800 
#9 7.801 npm ERR! code ELIFECYCLE
#9 7.801 npm ERR! errno 1
#9 7.801 npm ERR! heapdump@0.3.15 install: `node-gyp rebuild`
#9 7.801 npm ERR! Exit status 1
#9 7.801 npm ERR! 
#9 7.801 npm ERR! Failed at the heapdump@0.3.15 install script.
#9 7.801 npm ERR! This is probably not a problem with npm. There is likely additional logging output above.
#9 7.851 
#9 7.851 npm ERR! A complete log of this run can be found in:
#9 7.851 npm ERR!     /root/.npm/_logs/2022-03-14T07_11_01_659Z-debug.log
------

sanpj2292 commented 2 years ago

Can you try running transformer service alone ? Basically can you try running docker-compose up transformer ?

sanpj2292 commented 2 years ago

@laverdet ,

Checkout to the (branch)[https://github.com/rudderlabs/rudder-transformer/tree/user-tf-debug]
Run docker compose up transformer
Check if the service is up using :9091/health endpoint
Use Crash_nested_payload.json.txt & send a request to :9091/customTransform

I got an error like this when I performed the above steps:

$ docker compose up transformer

[+] Running 1/0
 ⠿ Container rudder-transformer-transformer-1  Created                                                                                                                                                   0.0s
Attaching to rudder-transformer-transformer-1
rudder-transformer-transformer-1  | 
rudder-transformer-transformer-1  | > rudder-transformer@0.1.5-rc.0 start /home/node/app
rudder-transformer-transformer-1  | > node destTransformer.js
rudder-transformer-transformer-1  | 
rudder-transformer-transformer-1  | Listening on Port: 9090 []
rudder-transformer-transformer-1 exited with code 139

Got an error code of 139. Please consider this as well while you're trying to debug the issue. Let me know if you need anything else.

Thanks

sanpj2292 commented 2 years ago

@laverdet ,

Hope the provided input is serving you well. If you're ok, we can connect on a call using zoom, google meets etc., and help you in debugging. Let me know if something like that can be worked out!

Thanks

laverdet / isolated-vm