search

gaffneyc / heroku-buildpack-jemalloc

Heroku buildpack that installs the Jemalloc memory allocator
BSD 3-Clause "New" or "Revised" License
252 stars 77 forks source link

jemalloc 5.1.0 causing problems in heroku deploys release phase #3

Closed concept47 closed 4 years ago

concept47 commented 6 years ago

Since the change of version of jemalloc, we've started getting failures in the release phase of our heroku deploys that look like this

  rake aborted!
  JSON::ParserError: 765: unexpected token at 'node[29]: pthread_create: Invalid argument
  ["ok"]'
  /app/vendor/bundle/ruby/2.5.0/gems/execjs-2.7.0/lib/execjs/external_runtime.rb:68:in `extract_result'
  /app/vendor/bundle/ruby/2.5.0/gems/execjs-2.7.0/lib/execjs/external_runtime.rb:39:in `exec'
  /app/vendor/bundle/ruby/2.5.0/gems/execjs-2.7.0/lib/execjs/external_runtime.rb:14:in `initialize'
  /app/vendor/bundle/ruby/2.5.0/gems/execjs-2.7.0/lib/execjs/runtime.rb:57:in `new'
  /app/vendor/bundle/ruby/2.5.0/gems/execjs-2.7.0/lib/execjs/runtime.rb:57:in `compile'
  /app/vendor/bundle/ruby/2.5.0/gems/execjs-2.7.0/lib/execjs/module.rb:27:in `compile'
  /app/vendor/bundle/ruby/2.5.0/gems/uglifier-4.1.10/lib/uglifier.rb:154:in `initialize'
  /app/config/environments/staging.rb:21:in `new'
  /app/config/environments/staging.rb:21:in `block in <main>'
  /app/vendor/bundle/ruby/2.5.0/gems/railties-5.0.6/lib/rails/railtie.rb:209:in `instance_eval'
  /app/vendor/bundle/ruby/2.5.0/gems/railties-5.0.6/lib/rails/railtie.rb:209:in `configure'
  /app/config/environments/staging.rb:1:in `<main>'
  /app/vendor/bundle/ruby/2.5.0/gems/bootsnap-1.2.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:19:in `require'
  /app/vendor/bundle/ruby/2.5.0/gems/bootsnap-1.2.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:19:in `block in require_with_bootsnap_lfi'
  /app/vendor/bundle/ruby/2.5.0/gems/bootsnap-1.2.0/lib/bootsnap/load_path_cache/loaded_features_index.rb:65:in `register'
  /app/vendor/bundle/ruby/2.5.0/gems/bootsnap-1.2.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:18:in `require_with_bootsnap_lfi'
  /app/vendor/bundle/ruby/2.5.0/gems/bootsnap-1.2.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:27:in `require'
  /app/vendor/bundle/ruby/2.5.0/gems/activesupport-5.0.6/lib/active_support/dependencies.rb:293:in `block in require'
  /app/vendor/bundle/ruby/2.5.0/gems/activesupport-5.0.6/lib/active_support/dependencies.rb:259:in `load_dependency'
  /app/vendor/bundle/ruby/2.5.0/gems/activesupport-5.0.6/lib/active_support/dependencies.rb:293:in `require'
  /app/vendor/bundle/ruby/2.5.0/gems/railties-5.0.6/lib/rails/engine.rb:600:in `block (2 levels) in <class:Engine>'
  /app/vendor/bundle/ruby/2.5.0/gems/railties-5.0.6/lib/rails/engine.rb:599:in `each'
  /app/vendor/bundle/ruby/2.5.0/gems/railties-5.0.6/lib/rails/engine.rb:599:in `block in <class:Engine>'
  /app/vendor/bundle/ruby/2.5.0/gems/railties-5.0.6/lib/rails/initializable.rb:30:in `instance_exec'
  /app/vendor/bundle/ruby/2.5.0/gems/railties-5.0.6/lib/rails/initializable.rb:30:in `run'
  /app/vendor/bundle/ruby/2.5.0/gems/railties-5.0.6/lib/rails/initializable.rb:55:in `block in run_initializers'
  /app/vendor/bundle/ruby/2.5.0/gems/railties-5.0.6/lib/rails/initializable.rb:44:in `each'
  /app/vendor/bundle/ruby/2.5.0/gems/railties-5.0.6/lib/rails/initializable.rb:44:in `tsort_each_child'
  /app/vendor/bundle/ruby/2.5.0/gems/railties-5.0.6/lib/rails/initializable.rb:54:in `run_initializers'
  /app/vendor/bundle/ruby/2.5.0/gems/railties-5.0.6/lib/rails/application.rb:352:in `initialize!'
  /app/config/environment.rb:5:in `<main>'
  /app/vendor/bundle/ruby/2.5.0/gems/bootsnap-1.2.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:19:in `require'
  /app/vendor/bundle/ruby/2.5.0/gems/bootsnap-1.2.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:19:in `block in require_with_bootsnap_lfi'
  /app/vendor/bundle/ruby/2.5.0/gems/bootsnap-1.2.0/lib/bootsnap/load_path_cache/loaded_features_index.rb:65:in `register'
  /app/vendor/bundle/ruby/2.5.0/gems/bootsnap-1.2.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:18:in `require_with_bootsnap_lfi'
  /app/vendor/bundle/ruby/2.5.0/gems/bootsnap-1.2.0/lib/bootsnap/load_path_cache/core_ext/kernel_require.rb:27:in `require'
  /app/vendor/bundle/ruby/2.5.0/gems/activesupport-5.0.6/lib/active_support/dependencies.rb:293:in `block in require'
  /app/vendor/bundle/ruby/2.5.0/gems/activesupport-5.0.6/lib/active_support/dependencies.rb:259:in `load_dependency'
  /app/vendor/bundle/ruby/2.5.0/gems/activesupport-5.0.6/lib/active_support/dependencies.rb:293:in `require'
  /app/vendor/bundle/ruby/2.5.0/gems/railties-5.0.6/lib/rails/application.rb:328:in `require_environment!'
  /app/vendor/bundle/ruby/2.5.0/gems/railties-5.0.6/lib/rails/application.rb:448:in `block in run_tasks_blocks'
  /app/vendor/bundle/ruby/2.5.0/gems/bugsnag-5.0.1/lib/bugsnag/rake.rb:12:in `execute_with_bugsnag'
  Tasks: TOP => db:migrate => environment
  (See full trace by running task with --trace)

The line in question in staging.rb that seems to fail is this one

     config.assets.js_compressor = Uglifier.new(harmony: true)

All our deploys with the jemalloc buildpack removed work just fine. (Figured this because our review apps don't use jemalloc, but it seemed that we had to run 

heroku plugins:install heroku-repo
heroku repo:purge_cache

To get it to work.

concept47 commented 6 years ago

https://github.com/jemalloc/jemalloc/issues/1313#issuecomment-415556057

alainravet commented 6 years ago

For those who can no longer deploy because of this issue: revert to the previous version

Fork this repo and revert to jemallock 5.0.1

  1. Fork this repo
  2. $ git clone <your fork repo> ; cd heroku-buildpack-jemalloc
  3. $ git reset --hard 08f77c0a
  4. $ git push -f

Use your modified buildpack

  1. open https://dashboard.heroku.com/apps/<your app>/settings ;
  2. scroll down to 'Buildbacks'
  3. deletehttps://github.com/gaffneyc/heroku-buildpack-jemalloc
  4. add https://github.com/<your-account>/heroku-buildpack-jemalloc
gaffneyc commented 6 years ago

You should be able to set JEMALLOC_VERSION=5.0.1 instead of having to fork the repo. I'm sorry you ran into issues, we had an open issue for about two months before upgrading... of course that requires people to be testing the new version against different environments to find anything. I also missed this since I apparently wasn't watching my own repo 🤦‍♂️

From your stack trace, the problem is actually coming from NodeJS and not Ruby. There was a note in #2 about NodeJS printing pthread_create: Invalid argument but otherwise working fine. My guess is that execjs is forking a NodeJS process then reading the output from the command and parsing the output as JSON. The problem is that the warning is breaking the parsing.

@concept47 If you're still in a position to, could you try setting JEMALLOC_VERSION to see if that fixes the issue?

concept47 commented 6 years ago

It worked a treat @gaffneyc. Thanks!

gaffneyc commented 6 years ago

I'm considering reverting the change to make 5.1.0 the default. If you've run into this then 👍 this comment and I'll take that into consideration. I hate to move backwards but I also don't want to break things for people.

jvdp commented 6 years ago

@gaffneyc I get a problem after release (running migrations) with jemalloc enabled, even with 5.0.1, on the heroku-16 stack. I'll experiment with other versions.

gaffneyc commented 6 years ago

@jvdp Can you give some specifics on the problem you're seeing? For example: are you getting a stack trace, memory usage is going up, or response times are worse, etc...

jvdp commented 6 years ago

@gaffneyc the same exception as OP pretty much. This is with ruby 2.5.3.

(It worked well with Heroku-18 but it turns out that breaks wkhtmltopdf.)

gaffneyc commented 6 years ago

@jvdp The issue itself is with NodeJS (being called through ExecJS). I haven't had a chance to dig into the problem with Node but there are two things worth experimenting with. If you're seeing it on 5.0.1 then that's a new issue we haven't seen before (make sure you're pushing a code change as just changing JEMALLOC_VERSION isn't enough since jemalloc is baked into the slug).

  1. Upgrade NodeJS The default version for Rails applications on Heroku is 8.10.0 it's possible the issue has been fixed in a newer version of Node. You might be able to use therubyracer or mini_racer to get a newer version of node for testing. Otherwise you'll probably want to add the nodejs buildpack and use it to configure the node version.

  2. Use jemalloc.sh Use the per dyno config for jemalloc where you disable it globally (JEMALLOC_ENABLED=false) then add jemalloc.sh at the beginning of your web and (maybe) worker lines. This will disable jemalloc when running migrations but use it to run the application.

jvdp commented 6 years ago

@gaffneyc thanks for the pointers! I think I wasn't actually running 5.0.1, I've retried with a code change after setting the version and now it seems to work OK!

adamlogic commented 6 years ago

The default version for Rails applications on Heroku is 8.10.0 it's possible the issue has been fixed in a newer version of Node. You might be able to use therubyracer or mini_racer to get a newer version of node for testing. Otherwise you'll probably want to add the nodejs buildpack and use it to configure the node version.

Just heads-up that I ran into this same issue using the nodejs buildpack and Node 9.5.0. JEMALLOC_VERSION=5.0.1 fixed it. 🤷‍♂️

Also, I got tripped up that simply setting JEMALLOC_VERSION and triggering a release is not sufficient. You must trigger a full build on your app to pull in the updated version. This made sense once I peeked at the buildpack code and understood how it worked, but I'm still confused because changing JEMALLOC_ENABLED does seem to have an immediate impact without running a full build.

gaffneyc commented 5 years ago

Has any one run into this issue recently? I tried to reproduce it a couple months ago and wasn't able to. Also, several things have changed in the months since the issue was first opened:

Would one of you that has run into the issue be willing to try out Jemalloc 5.1.0 again? Or even kick the tires on jemalloc 5.2.0?

ianwremmel commented 5 years ago

@gaffneyc I just ran into it with the default version today. Setting 5.0.1 fixed it.

  "engines": {
    "node": "10.13.0",
    "npm": "6.4.1",
    "yarn": "1.15.2"
  },
 "stack": "heroku-16",
  "buildpacks": [
    {
      "url": "https://github.com/gaffneyc/heroku-buildpack-jemalloc.git"
    },
    {
      "url": "heroku/nodejs"
    },
    {
      "url": "heroku/ruby"
    },
    {
      "url": "heroku-community/awscli"
    },
    {
      "url": "heroku-community/cli"
    }
  ]

This was the line in our code that threw, if that helps:

config.assets.js_compressor = Uglifier.new(harmony: true)
gaffneyc commented 5 years ago

@ianwremmel Would you be able to give jemalloc 5.2.0 a try? It's looking like it might be an issue with the Heroku 16 stack

ianwremmel commented 5 years ago

trying it now

ianwremmel commented 5 years ago

same problem with 5.2.0

gaffneyc commented 5 years ago

@ianwremmel Awesome, thank you for testing it!

gaffneyc commented 5 years ago

I've been able to reproduce the issue and I've created a minimal test repository for it if anyone wants to try to solve it.

I've done some initial digging and it appears the issue is fixed on the heroku-18 stack or when using NodeJS >= 12.4.0 on heroku-16 (or cedar-14).

cedar-14 heroku-16 heroku-18
Node 10.13.0 ❌ ❌ ✅
Node 10.14.1 (Rails Default) ❌ ❌ ✅
Node 10.16.0 ❌ ❌ ✅
Node 12.0.0 ❌ ❌ ✅
Node 12.3.1 ❌ ❌ ✅
Node 12.4.0 ✅ ✅ ✅

I've run a bisect on jemalloc and this appears to be the commit that introduced the issue: https://github.com/jemalloc/jemalloc/commit/9c0549007dcb64f4ff35d37390a9a6a8d3cea880

I am going to experiment with configure options to see if we can get builds working for cedar-14 and heroku-16. Since the problem will effectively go away as people move to Heroku 18 or newer versions of Node I'm not sure what else could be done.

Changes between 12.3.1 and 12.4.0

ianwremmel commented 5 years ago

@gaffneyc thanks for the update! We're looking to move to Heroku-18 in the coming weeks, so I think simply running on the older version is perfectly fine for us for the time being.

gaffneyc commented 5 years ago

After more research it looks like it was fixed in 12.4.0 with this commit and is triggered by thread stack size. Annoyingly, NodeJS is printing the message that is breaking Uglifier.

This is looking to be an issue in NodeJS (which has been fixed) that happens to be triggered by something in jemalloc. I've tested a number of build configs with jemalloc and none of them have addressed the issue.

Unfortunately I think the "fix" is to document the issue in the README and recommend folks use one of: Heroku 18, NodeJS 12.4.0+, or jemalloc 5.0.1 (in that order).

gaffneyc commented 4 years ago

Heroku should be updating Ruby apps to use Node 12.16.2 by default sometime soon which should close this out once and for all.

Initial release yesterday (June 22nd) that was rolled back: https://devcenter.herokuapp.com/changelog-items/1818

gaffneyc commented 4 years ago

Heroku finally rolled out the upgrade to Node 12.16.2 for Rails apps for all of their stacks. That should mean this is finally fixed for good (unless of course you're pinned to an old version of NodeJS with the NodeJS buildpack).

https://devcenter.herokuapp.com/changelog-items/1825