Illegal instruction (core dumped) node main.js

aikomastboom commented 2 years ago

it appears to happen when opening a chat/channel

rocketchat_1  | LocalStore: store created at
rocketchat_1  | LocalStore: store created at
rocketchat_1  | LocalStore: store created at
rocketchat_1  | {"level":51,"time":"2022-02-05T15:14:50.200Z","pid":20,"hostname":"5ad0e52c8591","name":"","name":"Migrations","msg":"Not migrating, already at version 253"}
rocketchat_1  | +----------------------------------------------------+
rocketchat_1  | |                   SERVER RUNNING                   |
rocketchat_1  | +----------------------------------------------------+
rocketchat_1  | |                                                    |
rocketchat_1  | |  Rocket.Chat Version: 4.4.0                        |
rocketchat_1  | |       NodeJS Version: 14.18.2 - x64                |
rocketchat_1  | |      MongoDB Version: 4.4.12                       |
rocketchat_1  | |       MongoDB Engine: wiredTiger                   |
rocketchat_1  | |             Platform: linux                        |
rocketchat_1  | |         Process Port: 3000                         |
rocketchat_1  | |             Site URL: https://rocket.chat.example.com  |
rocketchat_1  | |     ReplicaSet OpLog: Enabled                      |
rocketchat_1  | |          Commit Hash: f32fdfb363                   |
rocketchat_1  | |        Commit Branch: HEAD                         |
rocketchat_1  | |                                                    |
rocketchat_1  | +----------------------------------------------------+
rocketchat_1  | bash: line 2:    20 Illegal instruction     (core dumped) node main.js
rocketchat_1  | Tried 1 times. Waiting 5 secs...

code 20 Illegal instruction varies seemingly random: 152, 130, 108, 86, 42

$ docker version
Client: Docker Engine - Community
 Version:           20.10.10
 API version:       1.41
 Go version:        go1.16.9
 Git commit:        b485636
 Built:             Mon Oct 25 07:42:59 2021
 OS/Arch:           linux/amd64
 Context:           default
 Experimental:      true

Server: Docker Engine - Community
 Engine:
  Version:          20.10.10
  API version:      1.41 (minimum version 1.12)
  Go version:       go1.16.9
  Git commit:       e2f740d
  Built:            Mon Oct 25 07:41:08 2021
  OS/Arch:          linux/amd64
  Experimental:     false
 containerd:
  Version:          1.4.11
  GitCommit:        5b46e404f6b9f661a205e28d59c982d3634148f8
 runc:
  Version:          1.0.2
  GitCommit:        v1.0.2-0-g52b36a2
 docker-init:
  Version:          0.19.0
  GitCommit:        de40ad0

$ cat docker-compose.yml
version: '2'
services:

  rocketchat:
    image: rocketchat/rocket.chat:latest
    command: >
      bash -c
        "npm update ;
        for i in `seq 1 30`; do
          node main.js &&
          s=$$? && break || s=$$?;
          echo \"Tried $$i times. Waiting 5 secs...\";
          sleep 5;
        done; (exit $$s)"
    restart: unless-stopped
    environment:
      - PORT=3000
      - ROOT_URL=https://rocket.chat.example.com
      - MONGO_URL=mongodb://mongo.example.com:27017/rocketchat
      - MONGO_OPLOG_URL=mongodb://mongo.example.com:27017/local
      - MAIL_URL=smtp://smtp.example.com
      - HTTP_PROXY=http://192.168.0.1:3128
      - HTTPS_PROXY=http://192.168.0.1:3128
    ports:
      - "3000:3000"
    logging:
      driver: "json-file"
      options:
        max-size: "16m"
        max-file: "8"

sampaiodiego commented 2 years ago

not sure where did you get this docker-compose, but one thing that I found weird was the npm update command on rocket.chat service.. can you pls remove that and see what happens?

aikomastboom commented 2 years ago

hmm.. I think I added that once to fix a security warning.. I pulled the latest image and removed the npm update

And got the following log output after connecting (from my phone):

$ docker-compose up -d;\
> docker-compose logs --tail=50 --follow
Recreating rocket_rocketchat_1 ... done
Attaching to rocket_rocketchat_1
rocketchat_1  | LocalStore: store created at
rocketchat_1  | LocalStore: store created at
rocketchat_1  | LocalStore: store created at
rocketchat_1  | {"level":51,"time":"2022-02-09T08:09:17.354Z","pid":9,"hostname":"d2d23ba498f6","name":"","name":"Migrations","msg":"Migrating from version 253 -> 254"}
rocketchat_1  | {"level":51,"time":"2022-02-09T08:09:17.356Z","pid":9,"hostname":"d2d23ba498f6","name":"","name":"Migrations","msg":"Running up() on version 254"}
rocketchat_1  | Error creating index: users -> { bio: 1 } { unique: 1 } MongoError: Index build failed: 1e49eb73-3ff5-40d0-b471-3e0be280841b: Collection rocketchat.users ( be53e9b8-9697-4c5b-894e-ee3c384fc437 ) :: caused by :: E11000 duplicate key error collection: rocketchat.users index: bio_1 dup key: { bio: null }
rocketchat_1  |     at MessageStream.messageHandler (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/connection.js:272:20)
rocketchat_1  |     at MessageStream.emit (events.js:400:28)
rocketchat_1  |     at MessageStream.emit (domain.js:475:12)
rocketchat_1  |     at processIncomingData (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/message_stream.js:144:12)
rocketchat_1  |     at MessageStream._write (/app/bundle/programs/server/npm/node_modules/meteor/npm-mongo/node_modules/mongodb/lib/cmap/message_stream.js:42:5)
rocketchat_1  |     at writeOrBuffer (internal/streams/writable.js:358:12)
rocketchat_1  |     at MessageStream.Writable.write (internal/streams/writable.js:303:10)
rocketchat_1  |     at Socket.ondata (internal/streams/readable.js:731:22)
rocketchat_1  |     at Socket.emit (events.js:400:28)
rocketchat_1  |     at Socket.emit (domain.js:475:12)
rocketchat_1  |     at addChunk (internal/streams/readable.js:293:12)
rocketchat_1  |     at readableAddChunk (internal/streams/readable.js:267:9)
rocketchat_1  |     at Socket.Readable.push (internal/streams/readable.js:206:10)
rocketchat_1  |     at TCP.onStreamRead (internal/stream_base_commons.js:188:23)
rocketchat_1  |     at TCP.callbackTrampoline (internal/async_hooks.js:130:17) {
rocketchat_1  |   operationTime: Timestamp { _bsontype: 'Timestamp', low_: 1, high_: 1644394158 },
rocketchat_1  |   ok: 0,
rocketchat_1  |   code: 11000,
rocketchat_1  |   codeName: 'DuplicateKey',
rocketchat_1  |   keyPattern: { bio: 1 },
rocketchat_1  |   keyValue: { bio: null },
rocketchat_1  |   '$clusterTime': {
rocketchat_1  |     clusterTime: Timestamp { _bsontype: 'Timestamp', low_: 1, high_: 1644394158 },
rocketchat_1  |     signature: { hash: [Binary], keyId: 0 }
rocketchat_1  |   }
rocketchat_1  | }
rocketchat_1  | {"level":51,"time":"2022-02-09T08:09:18.600Z","pid":9,"hostname":"d2d23ba498f6","name":"","name":"Migrations","msg":"Finished migrating."}
rocketchat_1  | ufs: temp directory created at "/tmp/ufs"
rocketchat_1  | +----------------------------------------------------+
rocketchat_1  | |                   SERVER RUNNING                   |
rocketchat_1  | +----------------------------------------------------+
rocketchat_1  | |                                                    |
rocketchat_1  | |  Rocket.Chat Version: 4.4.1                        |
rocketchat_1  | |       NodeJS Version: 14.18.2 - x64                |
rocketchat_1  | |      MongoDB Version: 4.4.12                       |
rocketchat_1  | |       MongoDB Engine: wiredTiger                   |
rocketchat_1  | |             Platform: linux                        |
rocketchat_1  | |         Process Port: 3000                         |
rocketchat_1  | |             Site URL: https://rocket.chat.example.com  |
rocketchat_1  | |     ReplicaSet OpLog: Enabled                      |
rocketchat_1  | |          Commit Hash: 55598c2f75                   |
rocketchat_1  | |        Commit Branch: HEAD                         |
rocketchat_1  | |                                                    |
rocketchat_1  | +----------------------------------------------------+
rocketchat_1  | bash: line 2:     9 Illegal instruction     (core dumped) node main.js
rocketchat_1  | Tried 1 times. Waiting 5 secs...
rocketchat_1  | LocalStore: store created at
rocketchat_1  | LocalStore: store created at
rocketchat_1  | LocalStore: store created at
rocketchat_1  | {"level":51,"time":"2022-02-09T08:10:24.928Z","pid":31,"hostname":"d2d23ba498f6","name":"","name":"Migrations","msg":"Not migrating, already at version 254"}
rocketchat_1  | +----------------------------------------------------+
rocketchat_1  | |                   SERVER RUNNING                   |
rocketchat_1  | +----------------------------------------------------+
rocketchat_1  | |                                                    |
rocketchat_1  | |  Rocket.Chat Version: 4.4.1                        |
rocketchat_1  | |       NodeJS Version: 14.18.2 - x64                |
rocketchat_1  | |      MongoDB Version: 4.4.12                       |
rocketchat_1  | |       MongoDB Engine: wiredTiger                   |
rocketchat_1  | |             Platform: linux                        |
rocketchat_1  | |         Process Port: 3000                         |
rocketchat_1  | |             Site URL: https://rocket.chat.example.com  |
rocketchat_1  | |     ReplicaSet OpLog: Enabled                      |
rocketchat_1  | |          Commit Hash: 55598c2f75                   |
rocketchat_1  | |        Commit Branch: HEAD                         |
rocketchat_1  | |                                                    |
rocketchat_1  | +----------------------------------------------------+

aikomastboom commented 2 years ago

after updating image to 4.4.2


rocket-rocketchat-1  | LocalStore: store created at
rocket-rocketchat-1  | LocalStore: store created at
rocket-rocketchat-1  | LocalStore: store created at
rocket-rocketchat-1  | {"level":51,"time":"2022-02-11T07:52:32.046Z","pid":9,"hostname":"78474e8cb098","name":"","name":"Migrations","msg":"Not migrating, already at version 254"}
rocket-rocketchat-1  | ufs: temp directory created at "/tmp/ufs"
rocket-rocketchat-1  | +----------------------------------------------------+
rocket-rocketchat-1  | |                   SERVER RUNNING                   |
rocket-rocketchat-1  | +----------------------------------------------------+
rocket-rocketchat-1  | |                                                    |
rocket-rocketchat-1  | |  Rocket.Chat Version: 4.4.2                        |
rocket-rocketchat-1  | |       NodeJS Version: 14.18.2 - x64                |
rocket-rocketchat-1  | |      MongoDB Version: 4.4.12                       |
rocket-rocketchat-1  | |       MongoDB Engine: wiredTiger                   |
rocket-rocketchat-1  | |             Platform: linux                        |
rocket-rocketchat-1  | |         Process Port: 3000                         |
rocket-rocketchat-1  | |             Site URL: https://rocket.chat.example.com  |
rocket-rocketchat-1  | |     ReplicaSet OpLog: Enabled                      |
rocket-rocketchat-1  | |          Commit Hash: ec8011e94c                   |
rocket-rocketchat-1  | |        Commit Branch: HEAD                         |
rocket-rocketchat-1  | |                                                    |
rocket-rocketchat-1  | +----------------------------------------------------+
rocket-rocketchat-1  | Tried 1 times. Waiting 5 secs...
rocket-rocketchat-1  | bash: line 2:     9 Illegal instruction     (core dumped) node main.js

aikomastboom commented 2 years ago

upgraded node to 14.19.0 same effect
removed the HTTP_PROXY envs.. same effect
upgraded node to 16.14.0 but that resulted in the app not even starting: node: ../src/coroutine.cc:134: void* find_thread_id_key(void*): Assertion 'thread_id_key != 0x7777' failed.

sampaiodiego commented 2 years ago

right.. you don't need to change anything.. you should just run the published docker image..

what happens if you change the MONGO_URL env var to use a different database name? let's say MONGO_URL=mongodb://mongo.example.com:27017/testemptydb

I'm trying to find out if it is something related to the data you have or something related to you environment.

aikomastboom commented 2 years ago

I pointed the container to an empty database and as expected was greeted by the setup wizard. I could finish the wizard without a hitch. And send messages to myself. I did not go thru the steps to fully configure it, as that took me quite some time the first time around :) Node has not crashed yet.

Your hunch might be right.. it could very well be a data issue... how to proceed now?

craftbyte commented 2 years ago

I will say that same is happening to me, also with older data. Although I dont even get as far as the version screen. And new DB also didnt solve it. Running an older version 4.2.0 fixes the issue. 4.2.1 makes the issue appear.

aikomastboom commented 2 years ago

rocket-rocketchat-1  | +----------------------------------------------------+
rocket-rocketchat-1  | |                   SERVER RUNNING                   |
rocket-rocketchat-1  | +----------------------------------------------------+
rocket-rocketchat-1  | |                                                    |
rocket-rocketchat-1  | |  Rocket.Chat Version: 4.5.1                        |
rocket-rocketchat-1  | |       NodeJS Version: 14.18.3 - x64                |
rocket-rocketchat-1  | |      MongoDB Version: 4.4.12                       |
rocket-rocketchat-1  | |       MongoDB Engine: wiredTiger                   |
rocket-rocketchat-1  | |             Platform: linux                        |
rocket-rocketchat-1  | |         Process Port: 3000                         |
rocket-rocketchat-1  | |             Site URL: https://rocket.chat.example.com  |
rocket-rocketchat-1  | |     ReplicaSet OpLog: Enabled                      |
rocket-rocketchat-1  | |          Commit Hash: ec4397db0f                   |
rocket-rocketchat-1  | |        Commit Branch: HEAD                         |
rocket-rocketchat-1  | |                                                    |
rocket-rocketchat-1  | +----------------------------------------------------+
rocket-rocketchat-1  | bash: line 2:    11 Illegal instruction     (core dumped) node main.js

strangely.. it states a core is dumped.. but I could not find any in the container (to inspect).

aikomastboom commented 1 year ago

This issue is still hunting my instance:

Reproduction for me is easiest using the iOS app version 4.32.0 by just changing chat or refreshing one (pull down gesture)

if someone has an idea on how to trace this, or knows what to toggle in the container to get the server to start logging very much.. so I can pinpoint the origin of this.. would be very helpful.

rocket-rocketchat-1  | {"level":51,"time":"2022-11-19T09:27:06.211Z","pid":38,"hostname":"rocket.chat.example.com","name":"Migrations","msg":"Not migrating, already at version 281"}
rocket-rocketchat-1  | ufs: temp directory created at "/tmp/ufs"
rocket-rocketchat-1  | [DatabaseWatcher] Using change streams
rocket-rocketchat-1  | +----------------------------------------------------+
rocket-rocketchat-1  | |                   SERVER RUNNING                   |
rocket-rocketchat-1  | +----------------------------------------------------+
rocket-rocketchat-1  | |                                                    |
rocket-rocketchat-1  | |  Rocket.Chat Version: 5.3.2                        |
rocket-rocketchat-1  | |       NodeJS Version: 14.19.3 - x64                |
rocket-rocketchat-1  | |      MongoDB Version: 4.4.17                       |
rocket-rocketchat-1  | |       MongoDB Engine: wiredTiger                   |
rocket-rocketchat-1  | |             Platform: linux                        |
rocket-rocketchat-1  | |         Process Port: 3000                         |
rocket-rocketchat-1  | |             Site URL: https://rocket.chat.example.com  |
rocket-rocketchat-1  | |     ReplicaSet OpLog: Enabled                      |
rocket-rocketchat-1  | |          Commit Hash: 215a0685a5                   |
rocket-rocketchat-1  | |        Commit Branch: HEAD                         |
rocket-rocketchat-1  | |                                                    |
rocket-rocketchat-1  | +----------------------------------------------------+
rocket-rocketchat-1  | bash: line 6:    38 Illegal instruction     (core dumped) node main.js

GermanAizek commented 1 year ago

@aikomastboom, Most likely this is due to the fact that MongoDB 5.0+ requires AVX instructions, to solve this problem you need to build with my patch, or edit SConstruct build configuration file yourself. https://github.com/GermanAizek/mongodb-without-avx

aikomastboom commented 1 year ago

Not sure why that would be the issue, as I have not upgraded to MongoDB 5.0 yet.. The issue existed already when 5 was not the preferred version yet.

I still have been unable to enable some kind of debug logging / trace logging on the rocket server that could give a hint to when / where the code exits so brutally. How do the developers of the rocket project debug their work?

aikomastboom commented 5 months ago

Finally I got around to investigating a bit deeper. Turns out Rocket.Chat depends on sharp # High performance Node.js image processing Which in turn depends on a CPU flag SSE4_2. And as I am on a bit older hardware Apple Mac mini "Core 2 Duo" 2.66 (Mid-2010) this flag is not present on the P8800 cpu, rendering the precompiled binaries installed incompatible.

Running the image on a newer cpu (AMD Ryzen 7 4800U) in my case resolved this issue.

How I got the clue about sharp being an issue (Fontconfig seems of no consequence in this issue):

$ gdb node
...
> run main.js
...
[New Thread 0x7f7616d3b700 (LWP 3029)]
[New Thread 0x7f761653a700 (LWP 3030)]
[New Thread 0x7f7615d39700 (LWP 3031)]
[New Thread 0x7f7615538700 (LWP 3032)]
Fontconfig error: No writable cache directories
Fontconfig error: No writable cache directories
Fontconfig error: No writable cache directories
[New Thread 0x7f7614d37700 (LWP 3033)]

Thread 16 "[pango] FcInit" received signal SIGILL, Illegal instruction.
[Switching to Thread 0x7f7615538700 (LWP 3032)]
0x00007f76173bf17f in ?? () from /app/bundle/programs/server/npm/node_modules/sharp/build/Release/../.././vendor/8.14.5/linux-x64/lib/libvips-cpp.so.42

RocketChat / Docker.Official.Image

Illegal instruction (core dumped) node main.js #157