passenger_native_support.so not being downloaded/built #1950

msbit · 2017-05-21T17:29:13Z

Answer to questions below, but it looks like it's an issue with the PATH being cleared out somehow before/during invocation of /usr/share/passenger/helper-scripts/rack-preloader.rb.

Question 1: What is the problem?
On start, passenger is unable to build or fetch the passenger_native_support.so. In the logs we have the following:

App 9467 stdout:
App 9467 stderr:  [passenger_native_support.so] trying to compile for the current user (tom) and Ruby interpreter...
App 9467 stderr:
App 9467 stderr:      (set PASSENGER_COMPILE_NATIVE_SUPPORT_BINARY=0 to disable)
App 9467 stderr:
App 9467 stdout: /usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
App 9467 stderr:      Warning: compilation didn't succeed. To learn why, read this file:
App 9467 stderr:
App 9467 stderr:      /tmp/passenger_native_support-eyz7qt.log
App 9467 stderr:
App 9467 stderr:  [passenger_native_support.so] finding downloads for the current Ruby interpreter...
App 9467 stderr:
App 9467 stderr:      (set PASSENGER_DOWNLOAD_NATIVE_SUPPORT_BINARY=0 to disable)
App 9467 stderr:
App 9467 stderr:      Could not download https://oss-binaries.phusionpassenger.com/binaries/passenger/by_release/5.1.4/rubyext-ruby-2.1.9-x86-linux.tar.gz: no download tool found (curl or wget required)
App 9467 stderr:      Trying next mirror...
App 9467 stderr:      Could not download https://s3.amazonaws.com/phusion-passenger/binaries/passenger/by_release/5.1.4/rubyext-ruby-2.1.9-x86-linux.tar.gz: no download tool found (curl or wget required)
App 9467 stderr:  [passenger_native_support.so] will not be used (can't compile or download)
App 9467 stderr:
App 9467 stderr:   --> Passenger will still operate normally.
App 9467 stderr:
App 9467 stderr: /usr/share/passenger/helper-scripts/rack-preloader.rb: No such file or directory - uname
App 9467 stderr:
App 9467 stderr: Rack::File headers parameter replaces cache_control after Rack 1.5.
App 9467 stderr:
App 9467 stderr: sh: 1:
App 9467 stderr: env: not found
App 9467 stderr:

Contents of temp file:

# current user is: tom
# mkdir -p /home/tom/.passenger/native_support/5.1.4/ruby-2.1.9-x86-linux
# cd /home/tom/.passenger/native_support/5.1.4/ruby-2.1.9-x86-linux
# /usr/bin/ruby2.1 /usr/share/passenger/ruby_extension_source/extconf.rb
checking for alloca.h... *** /usr/share/passenger/ruby_extension_source/extconf.rb failed ***
Could not create Makefile due to some reason, probably lack of necessary
libraries and/or headers.  Check the mkmf.log file for more details.  You may
need configuration options.

Provided configuration options:
	--with-opt-dir
	--without-opt-dir
	--with-opt-include
	--without-opt-include=${opt-dir}/include
	--with-opt-lib
	--without-opt-lib=${opt-dir}/lib
	--with-make-prog
	--without-make-prog
	--srcdir=/usr/share/passenger/ruby_extension_source
	--curdir
	--ruby=/usr/bin/ruby2.1
/usr/lib/ruby/2.1.0/mkmf.rb:456:in `try_do': The compiler failed to generate an executable file. (RuntimeError)
You have to install development tools first.
	from /usr/lib/ruby/2.1.0/mkmf.rb:587:in `try_cpp'
	from /usr/lib/ruby/2.1.0/mkmf.rb:1061:in `block in have_header'
	from /usr/lib/ruby/2.1.0/mkmf.rb:912:in `block in checking_for'
	from /usr/lib/ruby/2.1.0/mkmf.rb:351:in `block (2 levels) in postpone'
	from /usr/lib/ruby/2.1.0/mkmf.rb:321:in `open'
	from /usr/lib/ruby/2.1.0/mkmf.rb:351:in `block in postpone'
	from /usr/lib/ruby/2.1.0/mkmf.rb:321:in `open'
	from /usr/lib/ruby/2.1.0/mkmf.rb:347:in `postpone'
	from /usr/lib/ruby/2.1.0/mkmf.rb:911:in `checking_for'
	from /usr/lib/ruby/2.1.0/mkmf.rb:1060:in `have_header'
	from /usr/share/passenger/ruby_extension_source/extconf.rb:38:in `<main>'

Contents of mkmf.log:

"gcc -o conftest -I/usr/include/i386-linux-gnu/ruby-2.1.0 -I/usr/include/ruby-2.1.0/ruby/backward -I/usr/include/ruby-2.1.0 -I/usr/share/passenger/ruby_extension_source -D_FORTIFY_SOURCE=2 -D_FILE_OFFSET_BITS=64  -g -O2 -fstack-protector --param=ssp-buffer-size=4 -Wformat -Wformat-security -Werror=format-security -fPIC -g conftest.c  -L. -L/usr/lib/i386-linux-gnu -L. -Wl,-Bsymbolic-functions -Wl,-z,relro -L/build/ruby2.1-CoNdM8/ruby2.1-2.1.9/debian/lib -fstack-protector -rdynamic -Wl,-export-dynamic     -lruby-2.1  -lpthread -lrt -lgmp -ldl -lcrypt -lm   -lc"
gcc: error trying to exec 'cc1': execvp: No such file or directory
checked program was:
/* begin */
1: #include "ruby.h"
2: 
3: int main(int argc, char **argv)
4: {
5:   return 0;
6: }
/* end */

Manually running the extconf.rb:

$ /usr/bin/ruby2.1 /usr/share/passenger/ruby_extension_source/extconf.rb
checking for alloca.h... yes
checking for ruby/version.h... yes
checking for ruby/io.h... yes
checking for ruby/thread.h... yes
checking for ruby_version... no
checking for rb_thread_io_blocking_region() in ruby/io.h... yes
checking for rb_thread_call_without_gvl() in ruby/thread.h... yes
creating Makefile

Presence of curl:

$ which curl
/usr/bin/curl

Question 2: Passenger version and integration mode:
Open-source 5.1.4/nginx

Question 3: OS or Linux distro, platform (including version):
Ubuntu 12.04.5 LTS i386

Question 4: Passenger installation method:
[ ] RubyGems + Gemfile
[ ] RubyGems, no Gemfile
[x] Phusion APT repo
[ ] Phusion YUM repo
[ ] OS X Homebrew
[ ] source tarball
[ ] Other, please specify:

Question 5: Your app's programming language (including any version managers) and framework (including versions):
Ruby 2.1.9
Rails 3.2.22.5

Question 6: Are you using a PaaS and/or containerization? If so which one?
No

Question 7: Anything else about your setup that we should know?
No

The text was updated successfully, but these errors were encountered:

CamJN · 2017-05-23T15:25:31Z

Couple more questions: how did you install the ruby you are using? And how are you specifying the ruby to passenger? In the http context or the server context? Lastly what happens if you run passenger-config build-native-support?

msbit · 2017-05-24T08:01:28Z

how did you install the ruby you are using?

From the BrightBox PPA (deb http://ppa.launchpad.net/brightbox/ruby-ng/ubuntu precise main)

how are you specifying the ruby to passenger?

In the http {..} stanza, included from passenger.conf (as per instructions from https://www.phusionpassenger.com/library/install/nginx/install/oss/precise/).

The Ruby itself is /usr/bin/passenger_free_ruby, which looks to do a automatic resolution of whichever Ruby is installed:

$ /usr/bin/passenger_free_ruby -v
ruby 2.1.9p490 (2016-03-30 revision 54437) [i386-linux-gnu]

what happens if you run passenger-config build-native-support?

$ passenger-config build-native-support
 [passenger_native_support.so] trying to compile for the current user (tom) and Ruby interpreter...
     (set PASSENGER_COMPILE_NATIVE_SUPPORT_BINARY=0 to disable)
     Compilation successful. The logs are here:
     /tmp/passenger_native_support-cbilnm.log
 [passenger_native_support.so] successfully loaded.

$ cat /tmp/passenger_native_support-cbilnm.log
# current user is: tom
# mkdir -p /home/tom/.passenger/native_support/5.1.4/ruby-2.1.9-x86-linux
# cd /home/tom/.passenger/native_support/5.1.4/ruby-2.1.9-x86-linux
# /usr/bin/ruby2.1 /usr/share/passenger/ruby_extension_source/extconf.rb
checking for alloca.h... yes
checking for ruby/version.h... yes
checking for ruby/io.h... yes
checking for ruby/thread.h... yes
checking for ruby_version... no
checking for rb_thread_io_blocking_region() in ruby/io.h... yes
checking for rb_thread_call_without_gvl() in ruby/thread.h... yes
creating Makefile
# make
compiling /usr/share/passenger/ruby_extension_source/passenger_native_support.c
linking shared-object passenger_native_support.so

msbit · 2017-05-24T08:04:21Z

As a follow up, now that this is built, looking over the logs I still see:

App 1789 stdout: 
App 1789 stderr: /usr/share/passenger/helper-scripts/rack-preloader.rb: No such file or directory - uname
App 1789 stderr: Rack::File headers parameter replaces cache_control after Rack 1.5.
App 1789 stderr: 
App 1789 stderr: sh: 1: 
App 1789 stderr: env: not found
App 1789 stderr:

which may indicate that uname and env/sh can't be found due to invalid/missing PATH.

CamJN · 2017-05-24T20:50:29Z

Just as a heads-up this is the last deb package we will be providing for Ubuntu 12.04, as it EOL'd in April. (see: https://lists.ubuntu.com/archives/ubuntu-announce/2017-March/000218.html and https://www.phusionpassenger.com/library/install/standalone/apt_repo/#limited-package-support-for-non-lts-ubuntu-versions)

As for the PATH issue, can you please set the passenger_log_level to 7 and grab the logs from the startup of passenger and your app, I recreated your setup as closely as I could and didn't run into this issue so I suspect that your .bashrc or .bash_profile files may be to blame. Passenger in log level 7 logs the setup of the bash shell used to launch your apps so it should provide some insight there.

msbit · 2017-05-24T23:49:17Z

Just as a heads-up this is the last deb package we will be providing for Ubuntu 12.04

The writing was on that wall :) Just to confirm, by that you that mean that version 1:5.1.4-1~precise1 is the last supported/provided deb?

can you please set the passenger_log_level to 7 and grab the logs from the startup of passenger and your app

Attached is the full /var/log/nginx/error.log (emptied before service nginx start)
error.log.txt, and below a selection of what is likely most relevant:

$ grep 'App 1816' error.log 
App 1816 stderr: + '[' '' ']'
App 1816 stderr: + '[' -d /etc/profile.d ']'
App 1816 stderr: + for i in '/etc/profile.d/*.sh'
App 1816 stderr: + '[' -r /etc/profile.d/Z97-byobu.sh ']'
App 1816 stderr: + . /etc/profile.d/Z97-byobu.sh
App 1816 stderr: ++ '[' -n '' ']'
App 1816 stderr: ++ '[' '' = byobu ']'
App 1816 stderr: ++ '[' '' = byobu-screen ']'
App 1816 stderr: ++ '[' '' = byobu-tmux ']'
App 1816 stderr: + for i in '/etc/profile.d/*.sh'
App 1816 stderr: + '[' -r /etc/profile.d/bash_completion.sh ']'
App 1816 stderr: + . /etc/profile.d/bash_completion.sh
App 1816 stderr: ++ '[' -z '4.2.25(1)-release' -o -z '' -o -n '' ']'
App 1816 stderr: ++ return
App 1816 stderr: + unset i
App 1816 stderr: + '[' -n '4.2.25(1)-release' ']'
App 1816 stderr: + '[' -f /home/tom/.bashrc ']'
App 1816 stderr: + . /home/tom/.bashrc
App 1816 stderr: ++ '[' -z '' ']'
App 1816 stderr: ++ return
App 1816 stderr: + '[' -d /home/tom/bin ']'
App 1816 stderr: + '[' -d /home/tom/.gem/ruby/2.1.0/bin ']'
App 1816 stderr: + PATH=/home/tom/.gem/ruby/2.1.0/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
App 1816 stderr: + exec /usr/lib/passenger/support-binaries/PassengerAgent spawn-preparer /home/tom/website SU5fUEFTU0VOR0VSADEAUFlUSE9OVU5CVUZGRVJFRAAxAE5PREVfUEFUSAAvdXNyL3NoYXJlL3Bhc3Nlbmdlci9ub2RlAFJBSUxTX0VOVgBwcm9kdWN0aW9uAFJBQ0tfRU5WAHByb2R1Y3Rpb24AV1NHSV9FTlYAcHJvZHVjdGlvbgBOT0RFX0VOVgBwcm9kdWN0aW9uAFBBU1NFTkdFUl9BUFBfRU5WAHByb2R1Y3Rpb24A /usr/bin/passenger_free_ruby /usr/bin/passenger_free_ruby /usr/share/passenger/helper-scripts/rack-preloader.rb
App 1816 stdout: 
[ 2017-05-25 09:36:01.7035 1790/b687eb40 age/Cor/Spa/Spawner.h:704 ]: [App 1816 stdout] !> I have control 1.0
[ 2017-05-25 09:36:01.7038 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] You have control 1.0
[ 2017-05-25 09:36:01.7038 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] passenger_root: /usr/lib/ruby/vendor_ruby/phusion_passenger/locations.ini
[ 2017-05-25 09:36:01.7038 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] ruby_libdir: /usr/lib/ruby/vendor_ruby
[ 2017-05-25 09:36:01.7038 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] passenger_version: 5.1.4
[ 2017-05-25 09:36:01.7038 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] UNIX_PATH_MAX: 108
[ 2017-05-25 09:36:01.7038 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] connect_password: rTepLCkZ4H9btqNZ
[ 2017-05-25 09:36:01.7039 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] instance_dir: /tmp/passenger.BoeOiNj
[ 2017-05-25 09:36:01.7039 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] socket_dir: /tmp/passenger.BoeOiNj/apps.s
[ 2017-05-25 09:36:01.7039 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] app_root: /home/tom/website
[ 2017-05-25 09:36:01.7039 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] app_group_name: /home/tom/website/public
[ 2017-05-25 09:36:01.7039 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] app_type: rack
[ 2017-05-25 09:36:01.7039 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] start_command: /usr/bin/passenger_free_ruby	/usr/share/passenger/helper-scripts/rack-loader.rb
[ 2017-05-25 09:36:01.7039 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] startup_file: /home/tom/website/config.ru
[ 2017-05-25 09:36:01.7039 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] process_title: Passenger RubyApp
[ 2017-05-25 09:36:01.7039 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] log_level: 7
[ 2017-05-25 09:36:01.7040 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] start_timeout: 90000
[ 2017-05-25 09:36:01.7040 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] environment: production
[ 2017-05-25 09:36:01.7040 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] base_uri: /
[ 2017-05-25 09:36:01.7040 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] spawn_method: smart
[ 2017-05-25 09:36:01.7040 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] default_user: nobody
[ 2017-05-25 09:36:01.7040 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] default_group: nogroup
[ 2017-05-25 09:36:01.7040 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] integration_mode: nginx
[ 2017-05-25 09:36:01.7040 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] ruby: /usr/bin/passenger_free_ruby
[ 2017-05-25 09:36:01.7040 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] python: python
[ 2017-05-25 09:36:01.7040 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] nodejs: node
[ 2017-05-25 09:36:01.7040 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] ust_router_address: unix:/tmp/passenger.BoeOiNj/agents.s/ust_router
[ 2017-05-25 09:36:01.7041 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] ust_router_username: logging
[ 2017-05-25 09:36:01.7041 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] ust_router_password: Zsu5EBYn5Sd9JYFF98Ueu3va
[ 2017-05-25 09:36:01.7041 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] debugger: false
[ 2017-05-25 09:36:01.7041 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] analytics: false
[ 2017-05-25 09:36:01.7041 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] api_key: rTepLCkZ4H9btqNZ
[ 2017-05-25 09:36:01.7041 1790/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 1816 stdin >>] 
App 1816 stderr: /usr/share/passenger/helper-scripts/rack-preloader.rb: No such file or directory - uname
App 1816 stderr: 
App 1816 stderr: Rack::File headers parameter replaces cache_control after Rack 1.5.
App 1816 stderr: 
App 1816 stderr: sh: 1: 
App 1816 stderr: env: not found
App 1816 stderr: 
[ 2017-05-25 09:36:08.7902 1790/b687eb40 age/Cor/Spa/Spawner.h:704 ]: [App 1816 stdout] !> Ready
[ 2017-05-25 09:36:08.7904 1790/b687eb40 age/Cor/Spa/Spawner.h:704 ]: [App 1816 stdout] !> socket: unix:/tmp/passenger.BoeOiNj/apps.s/preloader.2u01hg
[ 2017-05-25 09:36:08.7905 1790/b687eb40 age/Cor/Spa/Spawner.h:704 ]: [App 1816 stdout] !> 
App 1816 stderr: [ 2017-05-25 09:36:10.2207 1843/0x82b534c(Main thread) request_handler.rb:177 ]: Entering request handler main loop
App 1816 stderr: [ 2017-05-25 09:36:10.2278 1843/0x828c014(Worker 1) request_handler/thread_handler.rb:142 ]: Accepted new request on socket main socket
App 1816 stderr: cache: [GET /] miss
App 1816 stderr: [ 2017-05-25 09:36:10.3471 1843/0x828c014(Worker 1) request_handler/thread_handler.rb:342 ]: Keep-aliving connection.
App 1816 stderr: [ 2017-05-25 09:36:10.3500 1843/0x828c014(Worker 1) request_handler/thread_handler.rb:172 ]: Request done.

CamJN · 2017-05-25T14:34:34Z

Yes 1:5.1.4-1~precise1 is the last supported/provided deb for 12.04. As for the startup log, it actually looks fine which is all the stranger. Could you dump the ENV['PATH'] in /usr/share/passenger/helper-scripts/rack-preloader.rb before the GC.copy_on_write_friendly... line? If you leave the log level up you should be able to just write to stdout. I'm just wondering if the ruby process inherits the PATH correctly and then messes it up or if it's in the process of exec-ing the ruby process that the PATH is lost.

msbit · 2017-05-25T20:11:36Z

Could you dump the ENV['PATH'] in /usr/share/passenger/helper-scripts/rack-preloader.rb

Putting the following just before GC.copy_on_write_friendly...:

puts "ENV.keys:    #{ENV.keys}"
puts "ENV['PATH']: #{ENV['PATH']}"

prints the following in the log:

App 1511 stdout: ENV.keys:    ["SHELL", "PASSENGER_DEBUG_DIR", "USER", "PASSENGER_USE_FEEDBACK_FD", "PWD", "SHLVL", "HOME", "LOGNAME", "SERVER_SOFTWARE", "IN_PASSENGER", "PYTHONUNBUFFERED", "NODE_PATH", "RAILS_ENV", "RACK_ENV", "WSGI_ENV", "NODE_ENV", "PASSENGER_APP_ENV"]
App 1511 stdout: ENV['PATH']:

which seems to indicate that PATH is actually missing altogether at this point.

CamJN · 2017-05-25T20:30:46Z

Ok, so can you try setting passenger_ruby to the path to your ruby2.1 executable directly? That should determine if the problem is with passenger_free_ruby.

msbit · 2017-05-27T11:19:47Z

With passenger_ruby /usr/bin/ruby;:

tom@precise:~$ /usr/bin/ruby -v
ruby 2.1.9p490 (2016-03-30 revision 54437) [i386-linux-gnu]

tom@precise:~$ grep 'App 2421' error.log 
App 2421 stderr: + '[' '' ']'
App 2421 stderr: + '[' -d /etc/profile.d ']'
App 2421 stderr: + for i in '/etc/profile.d/*.sh'
App 2421 stderr: + '[' -r /etc/profile.d/Z97-byobu.sh ']'
App 2421 stderr: + . /etc/profile.d/Z97-byobu.sh
App 2421 stderr: ++ '[' -n '' ']'
App 2421 stderr: ++ '[' '' = byobu ']'
App 2421 stderr: ++ '[' '' = byobu-screen ']'
App 2421 stderr: ++ '[' '' = byobu-tmux ']'
App 2421 stderr: + for i in '/etc/profile.d/*.sh'
App 2421 stderr: + '[' -r /etc/profile.d/bash_completion.sh ']'
App 2421 stderr: + . /etc/profile.d/bash_completion.sh
App 2421 stderr: ++ '[' -z '4.2.25(1)-release' -o -z '' -o -n '' ']'
App 2421 stderr: ++ return
App 2421 stderr: + unset i
App 2421 stderr: + '[' -n '4.2.25(1)-release' ']'
App 2421 stderr: + '[' -f /home/tom/.bashrc ']'
App 2421 stderr: + . /home/tom/.bashrc
App 2421 stderr: ++ '[' -z '' ']'
App 2421 stderr: ++ return
App 2421 stderr: + '[' -d /home/tom/bin ']'
App 2421 stderr: + '[' -d /home/tom/.gem/ruby/2.1.0/bin ']'
App 2421 stderr: + PATH=/home/tom/.gem/ruby/2.1.0/bin:/usr/local/sbin:/usr/local/bin:/usr/sbin:/usr/bin:/sbin:/bin
App 2421 stderr: + exec /usr/lib/passenger/support-binaries/PassengerAgent spawn-preparer /home/tom/website SU5fUEFTU0VOR0VSADEAUFlUSE9OVU5CVUZGRVJFRAAxAE5PREVfUEFUSAAvdXNyL3NoYXJlL3Bhc3Nlbmdlci9ub2RlAFJBSUxTX0VOVgBwcm9kdWN0aW9uAFJBQ0tfRU5WAHByb2R1Y3Rpb24AV1NHSV9FTlYAcHJvZHVjdGlvbgBOT0RFX0VOVgBwcm9kdWN0aW9uAFBBU1NFTkdFUl9BUFBfRU5WAHByb2R1Y3Rpb24A /usr/bin/ruby /usr/bin/ruby /usr/share/passenger/helper-scripts/rack-preloader.rb
App 2421 stdout: 
App 2421 stdout: ENV.keys:    ["SHELL", "PASSENGER_DEBUG_DIR", "USER", "PASSENGER_USE_FEEDBACK_FD", "PWD", "SHLVL", "HOME", "LOGNAME", "SERVER_SOFTWARE", "IN_PASSENGER", "PYTHONUNBUFFERED", "NODE_PATH", "RAILS_ENV", "RACK_ENV", "WSGI_ENV", "NODE_ENV", "PASSENGER_APP_ENV"]
App 2421 stdout: ENV['PATH']: 
[ 2017-05-27 20:37:08.0064 2394/b687eb40 age/Cor/Spa/Spawner.h:704 ]: [App 2421 stdout] !> I have control 1.0
[ 2017-05-27 20:37:08.0070 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] You have control 1.0
[ 2017-05-27 20:37:08.0075 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] passenger_root: /usr/lib/ruby/vendor_ruby/phusion_passenger/locations.ini
[ 2017-05-27 20:37:08.0078 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] ruby_libdir: /usr/lib/ruby/vendor_ruby
[ 2017-05-27 20:37:08.0081 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] passenger_version: 5.1.4
[ 2017-05-27 20:37:08.0084 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] UNIX_PATH_MAX: 108
[ 2017-05-27 20:37:08.0088 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] connect_password: B8bH6bJwv6lKP1mp
[ 2017-05-27 20:37:08.0092 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] instance_dir: /tmp/passenger.nJR5nKm
[ 2017-05-27 20:37:08.0096 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] socket_dir: /tmp/passenger.nJR5nKm/apps.s
[ 2017-05-27 20:37:08.0099 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] app_root: /home/tom/website
[ 2017-05-27 20:37:08.0102 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] app_group_name: /home/tom/website/public
[ 2017-05-27 20:37:08.0106 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] app_type: rack
[ 2017-05-27 20:37:08.0110 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] start_command: /usr/bin/ruby	/usr/share/passenger/helper-scripts/rack-loader.rb
[ 2017-05-27 20:37:08.0113 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] startup_file: /home/tom/website/config.ru
[ 2017-05-27 20:37:08.0117 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] process_title: Passenger RubyApp
[ 2017-05-27 20:37:08.0119 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] log_level: 7
[ 2017-05-27 20:37:08.0121 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] start_timeout: 90000
[ 2017-05-27 20:37:08.0123 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] environment: production
[ 2017-05-27 20:37:08.0126 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] base_uri: /
[ 2017-05-27 20:37:08.0129 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] spawn_method: smart
[ 2017-05-27 20:37:08.0132 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] default_user: nobody
[ 2017-05-27 20:37:08.0134 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] default_group: nogroup
[ 2017-05-27 20:37:08.0136 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] integration_mode: nginx
[ 2017-05-27 20:37:08.0139 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] ruby: /usr/bin/ruby
[ 2017-05-27 20:37:08.0141 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] python: python
[ 2017-05-27 20:37:08.0142 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] nodejs: node
[ 2017-05-27 20:37:08.0144 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] ust_router_address: unix:/tmp/passenger.nJR5nKm/agents.s/ust_router
[ 2017-05-27 20:37:08.0145 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] ust_router_username: logging
[ 2017-05-27 20:37:08.0146 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] ust_router_password: h3dWdhReFr67cFBsBdmB3u6Y
[ 2017-05-27 20:37:08.0147 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] debugger: false
[ 2017-05-27 20:37:08.0147 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] analytics: false
[ 2017-05-27 20:37:08.0150 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] api_key: B8bH6bJwv6lKP1mp
[ 2017-05-27 20:37:08.0150 2394/b687eb40 age/Cor/Spa/SmartSpawner.h:388 ]: [App 2421 stdin >>] 
App 2421 stderr: /usr/share/passenger/helper-scripts/rack-preloader.rb: No such file or directory - uname
App 2421 stderr: 
App 2421 stderr: Rack::File headers parameter replaces cache_control after Rack 1.5.
App 2421 stderr: 
App 2421 stderr: sh: 1: 
App 2421 stderr: env: not found
App 2421 stderr: 
[ 2017-05-27 20:37:17.9016 2394/b687eb40 age/Cor/Spa/Spawner.h:704 ]: [App 2421 stdout] !> Ready
[ 2017-05-27 20:37:17.9021 2394/b687eb40 age/Cor/Spa/Spawner.h:704 ]: [App 2421 stdout] !> socket: unix:/tmp/passenger.nJR5nKm/apps.s/preloader.oaxsbe
[ 2017-05-27 20:37:17.9026 2394/b687eb40 age/Cor/Spa/Spawner.h:704 ]: [App 2421 stdout] !> 
App 2421 stderr: [ 2017-05-27 20:37:19.0395 2438/0x933d340(Main thread) request_handler.rb:177 ]: Entering request handler main loop
App 2421 stderr: [ 2017-05-27 20:37:19.0492 2438/0x9314044(Worker 1) request_handler/thread_handler.rb:142 ]: Accepted new request on socket main socket
App 2421 stderr: cache: [GET /] miss
App 2421 stderr: [ 2017-05-27 20:37:19.2824 2438/0x9314044(Worker 1) request_handler/thread_handler.rb:342 ]: Keep-aliving connection.
App 2421 stderr: [ 2017-05-27 20:37:19.2834 2438/0x9314044(Worker 1) request_handler/thread_handler.rb:172 ]: Request done.
App 2421 stderr: [ 2017-05-27 20:37:19.2844 2438/0x9314044(Worker 1) request_handler/thread_handler.rb:142 ]: Accepted new request on socket main socket
App 2421 stderr: cache: [GET /] reload
App 2421 stderr: [ 2017-05-27 20:37:19.3098 2438/0x9314044(Worker 1) request_handler/thread_handler.rb:342 ]: Keep-aliving connection.
App 2421 stderr: [ 2017-05-27 20:37:19.3104 2438/0x9314044(Worker 1) request_handler/thread_handler.rb:172 ]: Request done.
App 2421 stderr: [ 2017-05-27 20:37:19.9258 2449/0x933d340(Main thread) request_handler.rb:177 ]: Entering request handler main loop
App 2421 stderr: [ 2017-05-27 20:37:41.6114 2438/0x933d340(Main thread) request_handler.rb:485 ]: Owner pipe closed
App 2421 stderr: [ 2017-05-27 20:37:41.6117 2438/0x933d340(Main thread) request_handler.rb:547 ]: Waiting until all threads have become idle...
App 2421 stderr: [ 2017-05-27 20:37:41.6120 2438/0x933d340(Main thread) request_handler.rb:560 ]: There are currently 2 threads
App 2421 stderr: [ 2017-05-27 20:37:41.6136 2449/0x933d340(Main thread) request_handler.rb:485 ]: Owner pipe closed
App 2421 stderr: [ 2017-05-27 20:37:41.6150 2449/0x933d340(Main thread) request_handler.rb:547 ]: Waiting until all threads have become idle...
App 2421 stderr: [ 2017-05-27 20:37:41.6163 2449/0x933d340(Main thread) request_handler.rb:560 ]: There are currently 2 threads
App 2421 stderr: [ 2017-05-27 20:37:41.7135 2438/0x933d340(Main thread) request_handler.rb:605 ]: All threads are now idle
App 2421 stderr: [ 2017-05-27 20:37:41.7177 2438/0x933d340(Main thread) request_handler.rb:533 ]: Stopping all threads
App 2421 stderr: [ 2017-05-27 20:37:41.7193 2438/0x9314044(Worker 1) request_handler/thread_handler.rb:119 ]: Thread handler main loop exited normally
App 2421 stderr: [ 2017-05-27 20:37:41.7202 2438/0x93193b4(HTTP helper worker) request_handler/thread_handler.rb:119 ]: Thread handler main loop exited normally
App 2421 stderr: [ 2017-05-27 20:37:41.7207 2438/0x933d340(Main thread) request_handler.rb:543 ]: All threads stopped
App 2421 stderr: [ 2017-05-27 20:37:41.7235 2438/0x933d340(Main thread) request_handler.rb:205 ]: Request handler main loop exited normally
App 2421 stderr: [ 2017-05-27 20:37:41.7237 2438/0x933d340(Main thread) request_handler.rb:222 ]: Exiting request handler main loop
App 2421 stderr: [ 2017-05-27 20:37:41.7328 2449/0x933d340(Main thread) request_handler.rb:605 ]: All threads are now idle
App 2421 stderr: [ 2017-05-27 20:37:41.7402 2449/0x933d340(Main thread) request_handler.rb:533 ]: Stopping all threads
App 2421 stderr: [ 2017-05-27 20:37:41.7447 2449/0x93140e4(Worker 1) request_handler/thread_handler.rb:119 ]: Thread handler main loop exited normally
App 2421 stderr: [ 2017-05-27 20:37:41.7472 2449/0x931a14c(HTTP helper worker) request_handler/thread_handler.rb:119 ]: Thread handler main loop exited normally
App 2421 stderr: [ 2017-05-27 20:37:41.7493 2449/0x933d340(Main thread) request_handler.rb:543 ]: All threads stopped
App 2421 stderr: [ 2017-05-27 20:37:41.7601 2449/0x933d340(Main thread) request_handler.rb:205 ]: Request handler main loop exited normally
App 2421 stderr: [ 2017-05-27 20:37:41.7623 2449/0x933d340(Main thread) request_handler.rb:222 ]: Exiting request handler main loop

CamJN · 2017-05-29T19:05:14Z

what does file /usr/bin/ruby return?

msbit · 2017-06-03T03:31:44Z

@CamJN sorry about the delay there, I missed the notification.

$ file /usr/bin/ruby
/usr/bin/ruby: symbolic link to `/etc/alternatives/ruby'

$ update-alternatives --list ruby
/usr/bin/ruby2.1

$ update-alternatives --display ruby
ruby - auto mode
  link currently points to /usr/bin/ruby2.1
/usr/bin/ruby2.1 - priority 51
  slave erb: /usr/bin/erb2.1
  slave erb.1.gz: /usr/share/man/man1/erb2.1.1.gz
  slave irb: /usr/bin/irb2.1
  slave irb.1.gz: /usr/share/man/man1/irb2.1.1.gz
  slave rake: /usr/bin/rake2.1
  slave rake.1.gz: /usr/share/man/man1/rake2.1.1.gz
  slave rdoc: /usr/bin/rdoc2.1
  slave ri: /usr/bin/ri2.1
  slave ri.1.gz: /usr/share/man/man1/ri2.1.1.gz
  slave ruby.1.gz: /usr/share/man/man1/ruby2.1.1.gz
  slave testrb: /usr/bin/testrb2.1
Current 'best' version is '/usr/bin/ruby2.1'.

$ /usr/bin/ruby2.1 -v
ruby 2.1.9p490 (2016-03-30 revision 54437) [i386-linux-gnu]

CamJN · 2017-06-05T13:58:06Z

Ok so /usr/bin/ruby is a symlink to /etc/alternatives/ruby which is in turn a symlink to /usr/bin/ruby2.1. That shouldn't cause any changes to the env.

Does the line in your bash config that looks something like this: PATH=/home/tom/.gem/ruby/2.1.0/bin:$PATH have an export on it? I'm just wondering if something weird is happening where the PATH environment variable gets shadowed by a local variable in bash and then not inherited during the exec (that shouldn't happen but we're well past things making sense).

fschwahn · 2017-06-07T11:50:32Z

If this is not relevant to this issue I can open a separate one

I'm having the same problem on heroku, relevant logs:

Jun 07 13:41:49 app/web.1:  [passenger_native_support.so] will not be used (can't compile or download)  
Jun 07 13:41:49 app/web.1:   --> Passenger will still operate normally. 
Jun 07 13:41:49 app/web.1: =============== Phusion Passenger Standalone web server started =============== 
Jun 07 13:41:49 app/web.1: PID file: /app/passenger.53286.pid 
Jun 07 13:41:49 app/web.1: Log file: /app/log/passenger.53286.log 
Jun 07 13:41:49 app/web.1: Environment: production 
Jun 07 13:41:49 app/web.1: Accessible via: http://0.0.0.0:53286/ 
Jun 07 13:41:49 app/web.1: You can stop Phusion Passenger Standalone by pressing Ctrl-C. 
Jun 07 13:41:49 app/web.1: Problems? Check https://www.phusionpassenger.com/library/admin/standalone/troubleshooting/ 
Jun 07 13:41:49 app/web.1: =============================================================================== 
Jun 07 13:41:50 app/web.1: App 85 stdout:  
Jun 07 13:41:51 app/web.1: App 85 stderr:  [passenger_native_support.so] trying to compile for the current user (u30758) and Ruby interpreter... 
Jun 07 13:41:51 app/web.1: App 85 stderr:      (set PASSENGER_COMPILE_NATIVE_SUPPORT_BINARY=0 to disable) 
Jun 07 13:41:51 app/web.1: [ 2017-06-07 11:41:51.2552 34/7ff4462f3700 age/Cor/SecurityUpdateChecker.h:356 ]: Security update check: no update found (next check in 24 hours) 
Jun 07 13:41:52 app/web.1: App 85 stderr:      Warning: compilation didn't succeed. To learn why, read this file: 
Jun 07 13:41:52 app/web.1: App 85 stderr:      /tmp/passenger_native_support-1e2lc2m.log 
Jun 07 13:41:52 app/web.1: App 85 stderr:  [passenger_native_support.so] finding downloads for the current Ruby interpreter... 
Jun 07 13:41:52 app/web.1: App 85 stderr:      (set PASSENGER_DOWNLOAD_NATIVE_SUPPORT_BINARY=0 to disable) 
Jun 07 13:41:52 app/web.1: App 85 stderr:      Could not download https://oss-binaries.phusionpassenger.com/binaries/passenger/by_release/5.1.4/rubyext-ruby-2.2.7-x86_64-linux.tar.gz: The requested URL returned error: 404 Not Found 
Jun 07 13:41:52 app/web.1: App 85 stderr:      Trying next mirror... 
Jun 07 13:41:52 app/web.1: App 85 stderr:      Could not download https://s3.amazonaws.com/phusion-passenger/binaries/passenger/by_release/5.1.4/rubyext-ruby-2.2.7-x86_64-linux.tar.gz: The requested URL returned error: 403 Forbidden 
Jun 07 13:41:52 app/web.1: App 85 stderr:  [passenger_native_support.so] will not be used (can't compile or download)  
Jun 07 13:41:52 app/web.1: App 85 stderr:   --> Passenger will still operate normally.

We are using ruby 2.2.7, but if I check https://oss-binaries.phusionpassenger.com/binaries/passenger/by_release/5.1.4/ there is only a native binary for ruby 2.2.5.

msbit · 2017-06-07T12:25:07Z

Hey @fschwahn looks like that is a bit of a different issue, as in your case there is an attempt to fetch the extension, so it would be worth creating a new issue for this. More information for what went wrong is likely in /tmp/passenger_native_support-1e2lc2m.log, and that would be useful for adding to any issue you make.

OnixGH · 2017-06-07T12:29:33Z

@fschwahn the info you pasted is not enough to be considered an issue at this point. Native support is not required, and it's normal that not all binaries are available (we supply a few for convenience). It usually fails to compile if you don't have the necessary development tools installed (as @msbit said check the log).

fschwahn · 2017-06-07T12:37:28Z

Ok, the message threw me off, I thought this download is supposed to succeed - it seems having the download fail is the common case. Sorry for interrupting!

msbit · 2017-06-07T12:55:23Z

@CamJN interesting idea!. My PATH is set up in ~/.profile via:

# set PATH so it includes user's private bin if it exists
if [ -d "$HOME/bin" ] ; then
    PATH="$HOME/bin:$PATH"
fi

if [ -d "$HOME/.gem/ruby/2.1.0/bin" ] ; then
    PATH="$HOME/.gem/ruby/2.1.0/bin:$PATH"
fi

so no explicit export for PATH.

CamJN · 2017-06-07T13:33:11Z

@msbit interesting, .profile is actually a sh config, though it is often sourced from bash for the sake of ease of use. Is there a shebang (#!) line at the top of .profile and if so what does it say?

msbit · 2017-06-07T13:56:40Z

No shebang, full content of ~/.profile below:

$ cat ~/.profile 
# ~/.profile: executed by the command interpreter for login shells.
# This file is not read by bash(1), if ~/.bash_profile or ~/.bash_login
# exists.
# see /usr/share/doc/bash/examples/startup-files for examples.
# the files are located in the bash-doc package.

# the default umask is set in /etc/profile; for setting the umask
# for ssh logins, install and configure the libpam-umask package.
#umask 022

# if running bash
if [ -n "$BASH_VERSION" ]; then
    # include .bashrc if it exists
    if [ -f "$HOME/.bashrc" ]; then
	. "$HOME/.bashrc"
    fi
fi

# set PATH so it includes user's private bin if it exists
if [ -d "$HOME/bin" ] ; then
    PATH="$HOME/bin:$PATH"
fi

if [ -d "$HOME/.gem/ruby/2.1.0/bin" ] ; then
    PATH="$HOME/.gem/ruby/2.1.0/bin:$PATH"
fi

I've been looking through the code, and it does look like a login shell is created via the -l argument to bash, at src/agent/Core/SpawningKit/SmartSpawner.h, lines 110 or 112, so it would make sense that ~/.profile is included.

CamJN · 2017-06-07T14:30:08Z

Using .profile seems to be the issue, as this doesn't happen with .bash_profile. And it can be fixed by adding an export PATH="$PATH" line to the very end of the file.

msbit · 2017-06-08T03:58:33Z

@CamJN for me, if I replace .profile with .bash_profile (same contents) the issue still occurs. From https://www.gnu.org/software/bash/manual/bashref.html#Bash-Startup-Files this makes sense as:

When Bash is invoked as an interactive login shell, or as a non-interactive shell with the --login option, it first reads and executes commands from the file /etc/profile, if that file exists. After reading that file, it looks for ~/.bash_profile, ~/.bash_login, and ~/.profile, in that order, and reads and executes commands from the first one that exists and is readable. The --noprofile option may be used when the shell is started to inhibit this behavior.

I can confirm that adding export PATH=${PATH} at the end of ~/.profile makes sure that the PATH is passed to the:

exec /usr/lib/passenger/support-binaries/PassengerAgent spawn-preparer /home/tom/website <BASE64_ARGS>  /usr/bin/ruby2.1 /usr/bin/ruby2.1 /usr/share/passenger/helper-scripts/rack-preloader.rb

in the logs.

It's a little odd from my point of view though, as the server is effectively a completely new reinstall, and the ~/.profile only differs from the vanilla in the addition of:

if [ -d "$HOME/.gem/ruby/2.1.0/bin" ] ; then
    PATH="$HOME/.gem/ruby/2.1.0/bin:$PATH"
fi

Out of curiosity more than anything, I removed the ~/.profile file and tried that, but it had the same affect.

I've been trying to trace the execution flow, but I'm not sure where the Nginx code initially hands off to either PassengerAgent or whichever helper is dealing with the request.

CamJN · 2017-06-08T14:07:41Z

Bash is supposed to pass environment variables to its children, and after a variable is exported once it's supposed to be treated like an environment variable even if it gets shadowed but bash isn't doing that for some reason.

jmeridth · 2018-07-16T19:36:57Z

@msbit did you ever solve this?

msbit · 2018-07-17T01:18:40Z

@jmeridth unfortunately not.

It was for an older, unsupported version of Ubuntu and from memory it could be worked around so I didn’t look any further. My guess is the version of bash or general sh for that version of Ubuntu didn’t pass environment variables properly, but can’t be sure.

CamJN · 2018-07-17T14:42:29Z

@jmeridth feel free to include the details from your setup, especially a startup log with log level set to 7.

jemminger · 2018-09-07T23:16:39Z

Still happens to me with 5.2.0 and 5.3.4 on heroku.

2018-09-07T23:13:20.525834+00:00 heroku[release.4984]: Process exited with status 0
2018-09-07T23:13:22.342532+00:00 heroku[web.1]: Restarting
2018-09-07T23:13:22.343083+00:00 heroku[web.1]: State changed from up to starting
2018-09-07T23:13:22.972234+00:00 app[web.1]: App 111 stdout: {"lib":"que","hostname":"ef411ddd-13d2-41af-bf51-cd16765c75f8","pid":111,"thread":69842201157440,"event":"job_unavailable"}
2018-09-07T23:13:23.032766+00:00 app[web.1]: Stopping web server... done
2018-09-07T23:13:23.018086+00:00 heroku[web.1]: Stopping all processes with SIGTERM
2018-09-07T23:13:23.318989+00:00 heroku[web.1]: Process exited with status 2
2018-09-07T23:13:22.116210+00:00 app[api]: Release v20 created by user jeff@7compass.com
2018-09-07T23:13:50.351216+00:00 heroku[web.1]: Starting process with command `jemalloc.sh bundle exec passenger start -p 32937 --max-pool-size 3 --min-instances 2`
2018-09-07T23:13:53.413361+00:00 app[web.1]:  --> Downloading a Phusion Passenger agent binary for your platform
2018-09-07T23:13:53.645181+00:00 app[web.1]: 
2018-09-07T23:13:53.645192+00:00 app[web.1]:  --> Installing Nginx 1.12.2 engine
2018-09-07T23:13:53.827074+00:00 app[web.1]: 
2018-09-07T23:13:53.827121+00:00 app[web.1]: --------------------------
2018-09-07T23:13:53.827123+00:00 app[web.1]: 
2018-09-07T23:13:53.844791+00:00 app[web.1]:  [passenger_native_support.so] trying to compile for the current user (u21582) and Ruby interpreter...
2018-09-07T23:13:53.844794+00:00 app[web.1]:      (set PASSENGER_COMPILE_NATIVE_SUPPORT_BINARY=0 to disable)
2018-09-07T23:13:54.471994+00:00 app[web.1]:      Warning: compilation didn't succeed. To learn why, read this file:
2018-09-07T23:13:54.472045+00:00 app[web.1]:      /tmp/passenger_native_support-i93jj8.log
2018-09-07T23:13:54.472120+00:00 app[web.1]:  [passenger_native_support.so] finding downloads for the current Ruby interpreter...
2018-09-07T23:13:54.472146+00:00 app[web.1]:      (set PASSENGER_DOWNLOAD_NATIVE_SUPPORT_BINARY=0 to disable)
2018-09-07T23:13:55.203004+00:00 app[web.1]:      Could not download https://oss-binaries.phusionpassenger.com/binaries/passenger/by_release/5.2.0/rubyext-ruby-2.5.0-x86_64-linux.tar.gz: The requested URL returned error: 404 Not Found
2018-09-07T23:13:55.203396+00:00 app[web.1]:      Trying next mirror...
2018-09-07T23:13:55.544491+00:00 app[web.1]:      Could not download https://s3.amazonaws.com/phusion-passenger/binaries/passenger/by_release/5.2.0/rubyext-ruby-2.5.0-x86_64-linux.tar.gz: The requested URL returned error: 403 Forbidden
2018-09-07T23:13:55.544968+00:00 app[web.1]:  [passenger_native_support.so] will not be used (can't compile or download) 
2018-09-07T23:13:55.544995+00:00 app[web.1]:   --> Passenger will still operate normally.
2018-09-07T23:13:55.717891+00:00 heroku[web.1]: State changed from starting to up
2018-09-07T23:13:56.022078+00:00 app[web.1]: =============== Phusion Passenger Standalone web server started ===============
2018-09-07T23:13:56.022099+00:00 app[web.1]: PID file: /app/passenger.32937.pid
2018-09-07T23:13:56.022101+00:00 app[web.1]: Log file: /app/passenger.32937.log
2018-09-07T23:13:56.022103+00:00 app[web.1]: Environment: production
2018-09-07T23:13:56.022107+00:00 app[web.1]: Accessible via: http://0.0.0.0:32937/
2018-09-07T23:13:56.022109+00:00 app[web.1]: 
2018-09-07T23:13:56.022132+00:00 app[web.1]: You can stop Phusion Passenger Standalone by pressing Ctrl-C.
2018-09-07T23:13:56.022161+00:00 app[web.1]: Problems? Check https://www.phusionpassenger.com/library/admin/standalone/troubleshooting/
2018-09-07T23:13:56.022163+00:00 app[web.1]: ===============================================================================
2018-09-07T23:13:58.460178+00:00 app[web.1]: [ N 2018-09-07 23:13:58.4599 34/T7 age/Cor/SecurityUpdateChecker.h:507 ]: Security update check: no update found (next check in 24 hours)
2018-09-07T23:13:58.671005+00:00 app[web.1]: App 79 stdout: 
2018-09-07T23:13:59.324036+00:00 app[web.1]: App 79 stderr:  [passenger_native_support.so] trying to compile for the current user (u21582) and Ruby interpreter...
2018-09-07T23:13:59.324227+00:00 app[web.1]: App 79 stderr:      (set PASSENGER_COMPILE_NATIVE_SUPPORT_BINARY=0 to disable)
2018-09-07T23:14:00.069147+00:00 app[web.1]: App 79 stderr:      Warning: compilation didn't succeed. To learn why, read this file:
2018-09-07T23:14:00.069336+00:00 app[web.1]: App 79 stderr:      /tmp/passenger_native_support-1k21oht.log
2018-09-07T23:14:00.069375+00:00 app[web.1]: App 79 stderr:  [passenger_native_support.so] finding downloads for the current Ruby interpreter...
2018-09-07T23:14:00.069399+00:00 app[web.1]: App 79 stderr:      (set PASSENGER_DOWNLOAD_NATIVE_SUPPORT_BINARY=0 to disable)
2018-09-07T23:14:00.710363+00:00 app[web.1]: App 79 stderr:      Could not download https://oss-binaries.phusionpassenger.com/binaries/passenger/by_release/5.2.0/rubyext-ruby-2.5.0-x86_64-linux.tar.gz: The requested URL returned error: 404 Not Found
2018-09-07T23:14:00.710395+00:00 app[web.1]: App 79 stderr:      Trying next mirror...
2018-09-07T23:14:01.019868+00:00 app[web.1]: App 79 stderr:      Could not download https://s3.amazonaws.com/phusion-passenger/binaries/passenger/by_release/5.2.0/rubyext-ruby-2.5.0-x86_64-linux.tar.gz: The requested URL returned error: 403 Forbidden
2018-09-07T23:14:01.019982+00:00 app[web.1]: App 79 stderr:  [passenger_native_support.so] will not be used (can't compile or download) 
2018-09-07T23:14:01.020068+00:00 app[web.1]: App 79 stderr:   --> Passenger will still operate normally.

Tectract · 2018-10-06T03:49:57Z

Ran into this today. I can compile passenger_native_support.so from similar tarball source than the (failed) url that it tried. Where do I put it to make passenger stop complaining?

jemminger · 2018-10-06T03:54:17Z

A year and a half later...isn't this just an issue of putting the binaries on the proper cdn urls?

msbit · 2018-10-06T04:07:06Z

@jemminger the actual issue is not being able to compile passenger_native_support.so due to the environment not being passed along correctly to the build script.

msbit · 2018-10-06T04:45:54Z

@Tectract the best way to compile the missing file is via:

passenger-config build-native-support

This will build the file in the correct location, for me:

/home/tom/.gem/ruby/2.5.0/gems/passenger-5.3.5/buildout/ruby/ruby-2.5.1-x86_64-linux/passenger_native_support.so

CamJN · 2018-11-27T17:49:27Z

Closing as this is an issue with certain versions of bash not working correctly.

bubaflub · 2020-11-02T21:01:28Z

I was seeing this same problem and it turned out to be a configuration issue.

Similar to OP we have ~/.profile and compilation of native bindings was failing. The log file showed that the Makefile was successfully created but make failed because it failed to find things like cat, echo, and sed. Turning the log-level up to 7 I noticed that the app was being started with a bunch of environment variables that were all defined in our nginx configuration with passenger_env_var.

For some reason we were setting passenger_env_var PATH /usr/bin. This was overriding any PATH set by the shell or ~/.profile and on Ubuntu 18 echo and friends live in /bin, not /usr/bin. Once I deleted the configuration that set PATH native bindings build successfully.

FooBarWidget added the SupportCentral label May 21, 2017

FooBarWidget removed the SupportCentral label May 23, 2017

CamJN added the NeedsFeedback label May 23, 2017

FooBarWidget added the SupportCentral label May 24, 2017

FooBarWidget removed the SupportCentral label May 24, 2017

FooBarWidget added the SupportCentral label May 24, 2017

FooBarWidget removed the SupportCentral label May 25, 2017

FooBarWidget added the SupportCentral label May 25, 2017

FooBarWidget removed the SupportCentral label May 25, 2017

FooBarWidget added the SupportCentral label May 27, 2017

FooBarWidget removed the SupportCentral label May 29, 2017

FooBarWidget added the SupportCentral label Jun 3, 2017

FooBarWidget removed the SupportCentral label Jun 5, 2017

FooBarWidget added the SupportCentral label Jun 7, 2017

FooBarWidget removed the SupportCentral label Jun 7, 2017

FooBarWidget added the SupportCentral label Jun 7, 2017

FooBarWidget removed the SupportCentral label Jun 7, 2017

FooBarWidget added the SupportCentral label Jun 7, 2017

FooBarWidget removed the SupportCentral label Jun 7, 2017

FooBarWidget added the SupportCentral label Jun 8, 2017

FooBarWidget removed the SupportCentral label Jun 8, 2017

FooBarWidget added the SupportCentral label Jul 16, 2018

FooBarWidget removed the SupportCentral label Jul 17, 2018

FooBarWidget added the SupportCentral label Sep 7, 2018

CamJN closed this as completed Nov 27, 2018

FooBarWidget removed the SupportCentral label Nov 27, 2018

FooBarWidget added the SupportCentral label Nov 2, 2020

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

passenger_native_support.so not being downloaded/built #1950

passenger_native_support.so not being downloaded/built #1950

msbit commented May 21, 2017

CamJN commented May 23, 2017

msbit commented May 24, 2017

msbit commented May 24, 2017

CamJN commented May 24, 2017

msbit commented May 24, 2017 •

edited

Loading

CamJN commented May 25, 2017

msbit commented May 25, 2017

CamJN commented May 25, 2017

msbit commented May 27, 2017

CamJN commented May 29, 2017

msbit commented Jun 3, 2017

CamJN commented Jun 5, 2017

fschwahn commented Jun 7, 2017

msbit commented Jun 7, 2017

OnixGH commented Jun 7, 2017

fschwahn commented Jun 7, 2017

msbit commented Jun 7, 2017

CamJN commented Jun 7, 2017

msbit commented Jun 7, 2017

CamJN commented Jun 7, 2017

msbit commented Jun 8, 2017

CamJN commented Jun 8, 2017

jmeridth commented Jul 16, 2018

msbit commented Jul 17, 2018

CamJN commented Jul 17, 2018

jemminger commented Sep 7, 2018 •

edited

Loading

Tectract commented Oct 6, 2018

jemminger commented Oct 6, 2018

msbit commented Oct 6, 2018

msbit commented Oct 6, 2018

CamJN commented Nov 27, 2018

bubaflub commented Nov 2, 2020

passenger_native_support.so not being downloaded/built #1950

passenger_native_support.so not being downloaded/built #1950

Comments

msbit commented May 21, 2017

CamJN commented May 23, 2017

msbit commented May 24, 2017

msbit commented May 24, 2017

CamJN commented May 24, 2017

msbit commented May 24, 2017 • edited Loading

CamJN commented May 25, 2017

msbit commented May 25, 2017

CamJN commented May 25, 2017

msbit commented May 27, 2017

CamJN commented May 29, 2017

msbit commented Jun 3, 2017

CamJN commented Jun 5, 2017

fschwahn commented Jun 7, 2017

msbit commented Jun 7, 2017

OnixGH commented Jun 7, 2017

fschwahn commented Jun 7, 2017

msbit commented Jun 7, 2017

CamJN commented Jun 7, 2017

msbit commented Jun 7, 2017

CamJN commented Jun 7, 2017

msbit commented Jun 8, 2017

CamJN commented Jun 8, 2017

jmeridth commented Jul 16, 2018

msbit commented Jul 17, 2018

CamJN commented Jul 17, 2018

jemminger commented Sep 7, 2018 • edited Loading

Tectract commented Oct 6, 2018

jemminger commented Oct 6, 2018

msbit commented Oct 6, 2018

msbit commented Oct 6, 2018

CamJN commented Nov 27, 2018

bubaflub commented Nov 2, 2020

msbit commented May 24, 2017 •

edited

Loading

jemminger commented Sep 7, 2018 •

edited

Loading