Bug 984867 - Errno::ECONNREFUSED shown in /var/lib/openshift/<uuid>/ruby/logs/error_log with ruby-1.9 app
Summary: Errno::ECONNREFUSED shown in /var/lib/openshift/<uuid>/ruby/logs/error_log wi...
Keywords:
Status: CLOSED CURRENTRELEASE
Alias: None
Product: OpenShift Online
Classification: Red Hat
Component: Image
Version: 2.x
Hardware: Unspecified
OS: Unspecified
low
medium
Target Milestone: ---
: ---
Assignee: Michal Fojtik
QA Contact: libra bugs
URL:
Whiteboard:
Depends On:
Blocks:
TreeView+ depends on / blocked
 
Reported: 2013-07-16 08:43 UTC by Yan Du
Modified: 2015-05-15 00:33 UTC (History)
9 users (show)

Fixed In Version:
Doc Type: Bug Fix
Doc Text:
Clone Of:
Environment:
Last Closed: 2014-02-26 19:07:42 UTC
Target Upstream Version:
Embargoed:


Attachments (Terms of Use)


Links
System ID Private Priority Status Summary Last Updated
Red Hat Bugzilla 1044980 0 high CLOSED Ruby app trys to load module and connection is refused 2021-02-22 00:41:40 UTC
Red Hat Bugzilla 1089958 0 medium CLOSED Connection refused error on ruby-1.8 log 2021-02-22 00:41:40 UTC

Internal Links: 1044980 1089958

Description Yan Du 2013-07-16 08:43:16 UTC
Description of problem:
create a ruby-1.9 app, connect to the app to check the log in /var/lib/openshift/<uuid>/ruby/logs/, Errno::ECONNREFUSED shown


Version-Release number of selected component (if applicable):
STG(devenv-stage_406)
rhc-1.11.4



How reproducible:
Always



Steps to Reproduce:
1. create a ruby-1.9 app
   rhc app create r19 ruby-1.9
2. ssh into app
   rhc app ssh r19
3. check the log
   cat /var/lib/openshift/51e4feab2587c820ec00037a/ruby/logs/error_log-20130716-000000-EST



Actual results:

[r19-test.stg.rhcloud.com 51e4feab2587c820ec00037a]\> cat /var/lib/openshift/51e4feab2587c820ec00037a/ruby/logs/error_log-20130716-000000-EST 
[Tue Jul 16 04:05:32 2013] [notice] SELinux policy enabled; httpd running as context unconfined_u:system_r:openshift_t:s0:c3,c524
[Tue Jul 16 04:05:32 2013] [notice] Digest: generating secret for digest authentication ...
[Tue Jul 16 04:05:32 2013] [notice] Digest: done
[Tue Jul 16 04:05:32 2013] [notice] Apache/2.2.15 (Unix) Phusion_Passenger/3.0.17 configured -- resuming normal operations
/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/helper-scripts/prespawn:105:in `initialize': Connection refused - connect(2) (Errno::ECONNREFUSED)
    from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/helper-scripts/prespawn:105:in `new'
    from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/helper-scripts/prespawn:105:in `connect'
    from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/helper-scripts/prespawn:86:in `socket'
    from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/helper-scripts/prespawn:90:in `head_request'
    from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/helper-scripts/prespawn:145:in `<main>'
/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/helper-scripts/prespawn:105:in `initialize': Connection refused - connect(2) (Errno::ECONNREFUSED)
    from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/helper-scripts/prespawn:105:in `new'
    from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/helper-scripts/prespawn:105:in `connect'
    from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/helper-scripts/prespawn:86:in `socket'
    from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/helper-scripts/prespawn:90:in `head_request'
    from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.17/helper-scripts/prespawn:145:in `<main>'



Expected results:
no error shown.



Additional info:
no  error shown with ruby-1.8 app

Comment 1 Petr Brazdil 2013-08-21 09:48:07 UTC
I cannot reproduce this on latest devenv

Results are as expected.

[Wed Aug 21 05:38:46 2013] [notice] SELinux policy enabled; httpd running as context unconfined_u:system_r:openshift_t:s0:c0,c502
[Wed Aug 21 05:38:46 2013] [notice] Digest: generating secret for digest authentication ...
[Wed Aug 21 05:38:46 2013] [notice] Digest: done
[Wed Aug 21 05:38:46 2013] [notice] Apache/2.2.15 (Unix) Phusion_Passenger/3.0.21 configured -- resuming normal operations

Comment 2 Yan Du 2013-08-21 11:31:11 UTC
test OK on devenv_3680. but issue still can be reproduced on INT(devenv_3680).

Comment 3 Petr Brazdil 2013-08-22 14:01:30 UTC
Is there any way how to get direct access on INT devenv to test it?

If not I am not able to continue in fixing this bug.

Comment 4 Xiaoli Tian 2013-08-22 14:27:57 UTC
(In reply to Petr Brazdil from comment #3)
> Is there any way how to get direct access on INT devenv to test it?
> 
> If not I am not able to continue in fixing this bug.

To get logs, you could contact ops people, to reproduce it, INT(devenv_3680) means int.openshift.redhat.com which matches devenv_3680.

Comment 5 Gaoyun Pei 2013-10-15 07:21:15 UTC
Any progress of this bug?
I could reproduce this issue on OSE with package openshift-origin-cartridge-ruby-1.16.0-1.git.292.cb19e4f.el6op.noarch :)

Comment 9 Michal Fojtik 2013-11-05 13:58:22 UTC
Hi guys,

I think this bug is a lefover from:

https://bugzilla.redhat.com/show_bug.cgi?id=1022956

Passenger is trying to 'pre-spawn' the application, using the HEAD request. However, the HEAD request is fired against '127.0.0.1' and not against the application domain name. The request include 'Host' header, that should tell Apache, where to pass the request and 'wake up' the Rails application properly.

However, the request is made against port 8080:

HEAD 127.0.0.1:8080/
Host: 127.1.244.129 # -> Gear IP
...

In case of devenv, the request return 404, because the broker is running on port 8080? In case of INT or PROD, the port 8080 is not used and thus the 'Connection refused' is thrown into the application log.

In order to fix this bug:

1. The request must be made against the Apache which runs on the Gear
2. The correct port must be specified
3. The Host header must be processed correctly.

Comment 14 Yan Du 2014-01-09 10:18:28 UTC
The issue can't be reproduced on devenv_4200. 

[r19-111.dev.rhcloud.com 52ce69fbb604fc8d7900019b]\> cat ruby/logs/error_log-20140109-000000-EST 
[Thu Jan 09 04:21:19 2014] [notice] SELinux policy enabled; httpd running as context unconfined_u:system_r:openshift_t:s0:c0,c1005
[Thu Jan 09 04:21:19 2014] [notice] Digest: generating secret for digest authentication ...
[Thu Jan 09 04:21:19 2014] [notice] Digest: done
[Thu Jan 09 04:21:19 2014] [notice] Apache/2.2.15 (Unix) Phusion_Passenger/3.0.21 configured -- resuming normal operations


Will test it on INT/STG env after the INT/STG upgrade.

Comment 15 Michal Fojtik 2014-01-09 13:38:35 UTC
Nick, Yan Du,

I just tried in PROD and I can see the error in logs. This is due to PassengerSpawnIPAddress is ignored in Passenger configuration and Passenger is now doing the request to 127.0.0.1 instead of the application IP. In PROD 127.0.0.1 will return connection refused whereas in DEVENV 127.0.0.1 will respond correctly. I'm tempted to remove the PassengerSpawnIPAddress entirely and replace it with a curl command which will serve the same as prespawn. Any thoughts?

Comment 16 Michal Fojtik 2014-01-09 14:24:51 UTC
A PR that should fix this problem:

https://github.com/openshift/origin-server/pull/4440

Comment 17 openshift-github-bot 2014-01-10 14:53:04 UTC
Commit pushed to master at https://github.com/openshift/origin-server

https://github.com/openshift/origin-server/commit/cba1d7e85b9167f86c3f1ac584b47c80d2ea95de
Bug 984867 - Hardcode port 80 for PassengerPreStart

Comment 18 Meng Bo 2014-01-22 11:07:27 UTC
Checked on latest INT (devenv_4255), ths issue still can be reproduced.

$ cat ruby/logs/error_log-20140122-000000-EST 
[Wed Jan 22 06:03:15 2014] [notice] SELinux policy enabled; httpd running as context unconfined_u:system_r:openshift_t:s0:c2,c656
[Wed Jan 22 06:03:15 2014] [notice] Digest: generating secret for digest authentication ...
[Wed Jan 22 06:03:15 2014] [notice] Digest: done
[Wed Jan 22 06:03:15 2014] [notice] Apache/2.2.22 (Unix) Phusion_Passenger/3.0.21 configured -- resuming normal operations
/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/helper-scripts/prespawn:105:in `initialize': Connection refused - connect(2) (Errno::ECONNREFUSED)
	from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/helper-scripts/prespawn:105:in `new'
	from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/helper-scripts/prespawn:105:in `connect'
	from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/helper-scripts/prespawn:86:in `socket'
	from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/helper-scripts/prespawn:90:in `head_request'
	from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/helper-scripts/prespawn:145:in `<main>'
/opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/helper-scripts/prespawn:105:in `initialize': Connection refused - connect(2) (Errno::ECONNREFUSED)
	from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/helper-scripts/prespawn:105:in `new'
	from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/helper-scripts/prespawn:105:in `connect'
	from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/helper-scripts/prespawn:86:in `socket'
	from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/helper-scripts/prespawn:90:in `head_request'
	from /opt/rh/ruby193/root/usr/share/gems/gems/passenger-3.0.21/helper-scripts/prespawn:145:in `<main>'

Comment 19 Michal Fojtik 2014-01-22 14:35:42 UTC
Meng Bo: The problem should not be reproducible in PROD as the ports are now correct. 

See the description of this PR:

https://github.com/openshift/origin-server/pull/4440

Is it possible to VERIFY this in PROD once this fix land there?

Comment 22 Yan Du 2014-01-26 11:35:38 UTC
will retest the bug after the code merge to STG or PRO. Thanks.

Comment 23 Yan Du 2014-01-30 03:40:57 UTC
Test on PROD and STG(devenv_stage_666)

Issue still can be reproduced.

Comment 24 Michal Fojtik 2014-02-11 15:47:04 UTC
Yan Du the fix is not yet pushed into PROD, to verify it, you can rhc ssh into gear and cat ruby/etc/conf.d/openshift.conf file. You should see something like:

PassengerPreStart http://127.11.102.1:80/

instead of:

PassengerPreStart http://127.11.102.1:8080/

Comment 25 Yan Du 2014-02-12 07:20:46 UTC
Test on INT(devenv_4363), seem issue still can be reproduced.

[ruby19-111.int.rhcloud.com 52fb201403ef645237000001]\> cat ruby/etc/conf.d/openshift.conf | grep PassengerPreStart
PassengerPreStart http://127.5.128.129:8080/

Comment 26 Mrunal Patel 2014-02-12 16:02:00 UTC
Michal,
I am working with Troy on an updated passenger rpm that should resolve this issue.
So, need not use the APP_DNS is openshift.conf since the dns may not be available when the app is prespawned by passenger.

Comment 27 Michal Fojtik 2014-02-12 16:05:57 UTC
Mrunal: Thanks for update, does the update also fix the problem with the 80 port?

Comment 28 Mrunal Patel 2014-02-12 16:41:59 UTC
Michal,
I am not sure what the issue is with port 80. The rpm fix I have is replacing 127.0.0.1 by request_host in prespawn and that I think should fix the issue. I may have missed something?

Comment 29 Mrunal Patel 2014-02-13 06:21:08 UTC
The new passenger rpm should be available in latest devenv now. Could this be retested?

Comment 30 chunchen 2014-02-13 07:24:19 UTC
It's fixed, verified on devenv_4369, please refer to the results:

1. create a ruby-1.9 app
   rhc app create crb19s ruby-1.9 -s --no-git
2. ssh into app
   rhc app ssh crb19s
3. check the log
[crb19s-cdm.dev.rhcloud.com 52fc646500361b4cf70000e6]\> cat ~/ruby/logs/error_log-20140213-000000-EST
[Thu Feb 13 01:21:50 2014] [notice] SELinux policy enabled; httpd running as context unconfined_u:system_r:openshift_t:s0:c0,c1003
[Thu Feb 13 01:21:51 2014] [notice] Digest: generating secret for digest authentication ...
[Thu Feb 13 01:21:51 2014] [notice] Digest: done
[Thu Feb 13 01:21:51 2014] [notice] Apache/2.2.15 (Unix) Phusion_Passenger/3.0.21 configured -- resuming normal operations
[crb19s-cdm.dev.rhcloud.com 52fc646500361b4cf70000e6]\>


Note You need to log in before you can comment on or make changes to this bug.