When ElasticSearch is not ready the Web Site returns HTTP Error Status 500
Opened this issue · 0 comments
When testing the Web Site functionality in the Docker Cluster an early request right after startup returned an Error Response with HTTP Status Code 500.
$ docker logs perldoc_web
Container 'b224b1dad7d9.perldoc_web': 'entrypoint.sh' go ...
Container 'b224b1dad7d9.perldoc_web' - Network:
127.0.0.1^Ilocalhost$ ::1^Ilocalhost ip6-localhost ip6-loopback$ fe00::0^Iip6-localnet$ ff00::0^Iip6-mcastprefix$ ff02::1^Iip6-allnodes$ ff02::2^Iip6-allrouters$ 172.22.0.4^Ib224b1dad7d9$
Command: 'perldoc-browser.pl prefork'
Configuring Local Installation ...
PATH="/home/perldoc-browser/perl5/bin${PATH:+:${PATH}}"; export PATH;
PERL5LIB="/home/perldoc-browser/perl5/lib/perl5${PERL5LIB:+:${PERL5LIB}}"; export PERL5LIB;
PERL_LOCAL_LIB_ROOT="/home/perldoc-browser/perl5${PERL_LOCAL_LIB_ROOT:+:${PERL_LOCAL_LIB_ROOT}}"; export PERL_LOCAL_LIB_ROOT;
PERL_MB_OPT="--install_base \"/home/perldoc-browser/perl5\""; export PERL_MB_OPT;
PERL_MM_OPT="INSTALL_BASE=/home/perldoc-browser/perl5"; export PERL_MM_OPT;
Mojolicious Version: 9.21 [Code: '0']
Search Backend: es
Search::Elasticsearch Version: 7.715 [Code: '0']
Service 'perldoc-browser.pl': Launching ...
[2021-11-13 11:15:19.56782] [1] [info] Current cxns: ["http://elasticsearch:9200"]
[2021-11-13 11:15:19.56843] [1] [info] Forcing ping before next use on all live cxns
[2021-11-13 11:15:19.56905] [1] [info] Ping [http://elasticsearch:9200] before next request
[2021-11-13 11:15:22.76109] [1] [info] Listening at "http://*:3000"
[2021-11-13 11:15:22.79194] [1] [info] Manager 1 started
Web application available at http://127.0.0.1:3000
[2021-11-13 11:15:22.79551] [20] [info] Worker 20 started
[2021-11-13 11:15:22.79789] [21] [info] Worker 21 started
[2021-11-13 11:15:22.80021] [22] [info] Worker 22 started
[2021-11-13 11:15:22.80224] [1] [info] Creating process id file "/tmp/prefork.pid"
[2021-11-13 11:15:22.80238] [23] [info] Worker 23 started
[2021-11-13 11:15:33.54258] [22] [trace] [1fTb1D-4CPaJ] GET "/5.28.1/search"
[2021-11-13 11:15:33.54705] [22] [trace] [1fTb1D-4CPaJ] Routing to a callback
[2021-11-13 11:15:33.57935] [22] [info] Pinging [http://elasticsearch:9200]
[2021-11-13 11:15:33.72478] [22] [debug] [Cxn] ** [http://elasticsearch:9200]-[599] Could not connect to 'elasticsearch:9200': Connection refused, called from sub Search::Elasticsearch::Role::Client::Direct::__ANON__ at /home/perldoc-browser/lib/PerldocBrowser/Plugin/PerldocSearch/Elastic.pm line 416. With vars: {'request' => {'method' => 'HEAD','timeout' => 2,'path' => '/'},'status_code' => 599}
[2021-11-13 11:15:33.72536] [22] [info] Marking [http://elasticsearch:9200] as dead. Next ping at: Sat Nov 13 11:16:33 2021
[2021-11-13 11:15:33.74344] [22] [fatal] [NoNodes] ** No nodes are available: [http://elasticsearch:9200], called from sub Search::Elasticsearch::Role::Client::Direct::__ANON__ at /home/perldoc-browser/lib/PerldocBrowser/Plugin/PerldocSearch/Elastic.pm line 416.
[2021-11-13 11:15:33.75797] [22] [error] [1fTb1D-4CPaJ] [NoNodes] ** No nodes are available: [http://elasticsearch:9200], called from sub Search::Elasticsearch::Role::Client::Direct::__ANON__ at /home/perldoc-browser/lib/PerldocBrowser/Plugin/PerldocSearch/Elastic.pm line 416.
[2021-11-13 11:15:33.76035] [22] [trace] [1fTb1D-4CPaJ] Template "exception.development.html.ep" not found
[2021-11-13 11:15:33.76088] [22] [trace] [1fTb1D-4CPaJ] Template "exception.html.ep" not found
[2021-11-13 11:15:33.76124] [22] [trace] [1fTb1D-4CPaJ] Rendering template "mojo/debug.html.ep"
[2021-11-13 11:15:33.82467] [22] [trace] Your secret passphrase needs to be changed
[2021-11-13 11:15:33.83005] [22] [debug] [1fTb1D-4CPaJ] 500 Internal Server Error (0.287459s, 3.479/s)
which is a common behaviour when an unexpected uncaught exception happens in the Web Site.
This gives the appearance of an untreated error within the application logic (like syntax error or call on undef error) which is an unexpected response for the end user.
Due to the slow ElasticSearch startup this is rather likely to happen on each ElasticSearch restart.
Because of the stateless nature of each HTTP Request it is not easy to recognize whether this happened because the ElasticSearch is still starting up or it has actually crashed.
So, a more appropriate and comprehensible Response would be HTTP Status Code 503 Service Unavailable which indicates a temporary unavailability
Error 503 Documentation
the server is not ready to handle the request