Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

jemalloc 5.1.0 causing problems in heroku deploys release phase #3

Closed
concept47 opened this issue Aug 23, 2018 · 22 comments
Closed

jemalloc 5.1.0 causing problems in heroku deploys release phase #3

concept47 opened this issue Aug 23, 2018 · 22 comments

Comments

@concept47
Copy link

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 concept47 changed the title Jemalloc 5.1.0 causing problems in heroku deploys release phase jemalloc 5.1.0 causing problems in heroku deploys release phase Aug 23, 2018
@concept47
Copy link
Author

@alainravet
Copy link

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 08f77c0
  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
Copy link
Owner

gaffneyc commented Sep 4, 2018

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
Copy link
Author

It worked a treat @gaffneyc. Thanks!

@gaffneyc
Copy link
Owner

gaffneyc commented Sep 5, 2018

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
Copy link

jvdp commented Nov 19, 2018

@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
Copy link
Owner

gaffneyc commented Nov 19, 2018

@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
Copy link

jvdp commented Nov 19, 2018

@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
Copy link
Owner

@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
Copy link

jvdp commented Nov 20, 2018

@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
Copy link

adamlogic commented Nov 21, 2018

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
Copy link
Owner

gaffneyc commented May 7, 2019

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
Copy link

@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
Copy link
Owner

@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
Copy link

trying it now

@ianwremmel
Copy link

same problem with 5.2.0

@gaffneyc
Copy link
Owner

@ianwremmel Awesome, thank you for testing it!

@gaffneyc
Copy link
Owner

gaffneyc commented Jun 23, 2019

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:
jemalloc/jemalloc@9c05490

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
Copy link

@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
Copy link
Owner

gaffneyc commented Oct 2, 2019

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
Copy link
Owner

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
Copy link
Owner

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

6 participants