Hi, we're seeing a lot internal server error emails from the nav-server: "[Django] ERROR (EXTERNAL IP): Internal Server Error: /graphite/render"
Internal Server Error: /graphite/render Traceback (most recent call last): File "/usr/lib/python2.7/dist-packages/django/core/handlers/base.py", line 111, in get_response response = wrapped_callback(request, *callback_args, **callback_kwargs) File "/usr/lib/python2.7/dist-packages/nav/web/graphite/views.py", line 44, in index proxy = urlopen(req) File "/usr/lib/python2.7/urllib2.py", line 154, in urlopen return opener.open(url, data, timeout) File "/usr/lib/python2.7/urllib2.py", line 435, in open response = meth(req, response) File "/usr/lib/python2.7/urllib2.py", line 548, in http_response 'http', request, response, code, msg, hdrs) File "/usr/lib/python2.7/urllib2.py", line 473, in error return self._call_chain(*args) File "/usr/lib/python2.7/urllib2.py", line 407, in _call_chain result = func(*args) File "/usr/lib/python2.7/urllib2.py", line 556, in http_error_default raise HTTPError(req.get_full_url(), code, msg, hdrs, fp) HTTPError: HTTP Error 400: BAD REQUEST
Do you have any recommended steps for troubleshooting the issue?
best regards Andreas Dobloug USIT/UiO
I received ~180 of these emails yesterday... I don't know if this has been happening before we upgraded our server to debian 9, because the old installation did not send any emails because of an error in nav.conf.
[...] 'SCRIPT_FILENAME': '/usr/share/pyshared/nav/wsgi.py', 'SCRIPT_NAME': u'', 'SERVER_ADDR': '129.240.2.12', 'SERVER_ADMIN': 'webmaster@localhost', 'SERVER_NAME': 'nav.uio.no', 'SERVER_PORT': '443', 'SERVER_PROTOCOL': 'HTTP/1.1', 'SERVER_SIGNATURE': '<address>Apache/2.4.25 (Debian) Server at nav.uio.no Port 443</address>\n', 'SERVER_SOFTWARE': 'Apache/2.4.25 (Debian)', 'SSL_TLS_SNI': 'nav.uio.no', 'apache.version': (2, 4, 25), 'mod_wsgi.application_group': '', 'mod_wsgi.callable_object': 'application', 'mod_wsgi.daemon_connects': '1', 'mod_wsgi.daemon_restarts': '0', 'mod_wsgi.daemon_start': '1516041245352388', 'mod_wsgi.enable_sendfile': '0', 'mod_wsgi.handler_script': '', 'mod_wsgi.ignore_activity': '0', 'mod_wsgi.listener_host': '', 'mod_wsgi.listener_port': '443', 'mod_wsgi.path_info': '/graphite/render', 'mod_wsgi.process_group': 'NAV', 'mod_wsgi.queue_start': '1516041245352280', 'mod_wsgi.request_handler': 'wsgi-script', 'mod_wsgi.request_id': 'xuDk22Sjx2M', 'mod_wsgi.request_start': '1516041245352134', 'mod_wsgi.script_name': '', 'mod_wsgi.script_reloading': '1', 'mod_wsgi.script_start': '1516041245352425', 'mod_wsgi.thread_id': 2, 'mod_wsgi.thread_requests': 3765L, 'mod_wsgi.total_requests': 17840L, 'mod_wsgi.version': (4, 5, 11), 'wsgi.errors': <mod_wsgi.Log object at 0x7fb42c574a30>, 'wsgi.file_wrapper': <type 'mod_wsgi.FileWrapper'>, 'wsgi.input': <mod_wsgi.Input object at 0x7fb4347e8f10>, 'wsgi.multiprocess': True, 'wsgi.multithread': True, 'wsgi.run_once': False, 'wsgi.url_scheme': 'https', 'wsgi.version': (1, 0)}>
-----Original Message----- From: nav-users-request@uninett.no [mailto:nav-users-request@uninett.no] On Behalf Of Andreas Dobloug Sent: Friday, January 12, 2018 1:08 PM To: nav-users@uninett.no Subject: Internal Server Error: /graphite/render
Hi, we're seeing a lot internal server error emails from the nav-server: "[Django] ERROR (EXTERNAL IP): Internal Server Error: /graphite/render"
Internal Server Error: /graphite/render Traceback (most recent call last): File "/usr/lib/python2.7/dist-packages/django/core/handlers/base.py", line 111, in get_response response = wrapped_callback(request, *callback_args, **callback_kwargs) File "/usr/lib/python2.7/dist-packages/nav/web/graphite/views.py", line 44, in index proxy = urlopen(req) File "/usr/lib/python2.7/urllib2.py", line 154, in urlopen return opener.open(url, data, timeout) File "/usr/lib/python2.7/urllib2.py", line 435, in open response = meth(req, response) File "/usr/lib/python2.7/urllib2.py", line 548, in http_response 'http', request, response, code, msg, hdrs) File "/usr/lib/python2.7/urllib2.py", line 473, in error return self._call_chain(*args) File "/usr/lib/python2.7/urllib2.py", line 407, in _call_chain result = func(*args) File "/usr/lib/python2.7/urllib2.py", line 556, in http_error_default raise HTTPError(req.get_full_url(), code, msg, hdrs, fp) HTTPError: HTTP Error 400: BAD REQUEST
Do you have any recommended steps for troubleshooting the issue?
best regards Andreas Dobloug USIT/UiO
On Fri, 12 Jan 2018 12:07:43 +0000 Andreas Dobloug andreas.dobloug@usit.uio.no wrote:
Internal Server Error: /graphite/render Traceback (most recent call last): File "/usr/lib/python2.7/dist-packages/django/core/handlers/base.py", line 111, in get_response response = wrapped_callback(request, *callback_args, **callback_kwargs) File "/usr/lib/python2.7/dist-packages/nav/web/graphite/views.py", line 44, in index proxy = urlopen(req) File "/usr/lib/python2.7/urllib2.py", line 154, in urlopen return opener.open(url, data, timeout) File "/usr/lib/python2.7/urllib2.py", line 435, in open response = meth(req, response) File "/usr/lib/python2.7/urllib2.py", line 548, in http_response 'http', request, response, code, msg, hdrs) File "/usr/lib/python2.7/urllib2.py", line 473, in error return self._call_chain(*args) File "/usr/lib/python2.7/urllib2.py", line 407, in _call_chain result = func(*args) File "/usr/lib/python2.7/urllib2.py", line 556, in http_error_default raise HTTPError(req.get_full_url(), code, msg, hdrs, fp) HTTPError: HTTP Error 400: BAD REQUEST
Do you have any recommended steps for troubleshooting the issue?
This means NAV gets a "400 BAD REQUEST" error when attempting to contact your graphite-web server for a graph rendering request, which means you should check the logs of your graphite-web server.
This means NAV gets a "400 BAD REQUEST" error when attempting to contact your graphite-web server for a graph rendering request, which means you should check the logs of your graphite-web server.
We have done extensive debugging on this, and our graphite server is not the culprit.
NAV generates a call to <nav server>/graphite/render?format=json&from=-5min&until=now This is the first of many calls to /graphite/render on the device pages. All the other calls to /graphite/render looks to be working.
best regards
Andreas Dobloug USIT/UiO
On Wed, 31 Jan 2018 09:40:32 +0000 Andreas Dobloug andreas.dobloug@usit.uio.no wrote:
This means NAV gets a "400 BAD REQUEST" error when attempting to contact your graphite-web server for a graph rendering request, which means you should check the logs of your graphite-web server.
We have done extensive debugging on this, and our graphite server is not the culprit.
I did not say the Graphite server was the culprit. The graphite server returns "400 BAD REQUEST", which is why I asked you to inspect its logs. Specifically, I would be interested in knowing which request from NAV that caused it to report this.
We have done extensive debugging on this, and our graphite server is not the culprit.
I did not say the Graphite server was the culprit. The graphite server returns "400 BAD REQUEST", which is why I asked you to inspect its logs. Specifically, I would be interested in knowing which request from NAV that caused it to report this.
According to the sysadmin responsible for graphite, the request never reaches the graphite api.
This is the faulty request which generates the errors: https://nav.uio.no/graphite/render?format=json&from=-5min&until=now
The request does not contain a target.
best regards Andreas Dobloug USIT/UiO
On Thu, 1 Feb 2018 10:06:41 +0000 Andreas Dobloug andreas.dobloug@usit.uio.no wrote:
We have done extensive debugging on this, and our graphite server is not the culprit.
I did not say the Graphite server was the culprit. The graphite server returns "400 BAD REQUEST", which is why I asked you to inspect its logs. Specifically, I would be interested in knowing which request from NAV that caused it to report this.
According to the sysadmin responsible for graphite, the request never reaches the graphite api.
But according to your traceback, it does.
This is the faulty request which generates the errors: https://nav.uio.no/graphite/render?format=json&from=-5min&until=now
The request does not contain a target.
That's interesting on several levels.
Firstly, the NAV request is obviously botched, but where does it come from? Did NAV generate it, or did something else? You neglected to include the rest of the e-mail sent by Django. Do your NAV webserver logs contain referrer information for the failing request?
Secondly: Which version of graphite-web are you running? I'm unable to make this request crash on any NAV installation I have access to. It simply returns an empty JSON response. 0.9.12 is the running version on those I have access to.
On Thu, 8 Feb 2018 08:46:14 +0100 Morten Brekkevold morten.brekkevold@uninett.no wrote:
This is the faulty request which generates the errors: https://nav.uio.no/graphite/render?format=json&from=-5min&until=now
The request does not contain a target.
That's interesting on several levels.
Firstly, the NAV request is obviously botched, but where does it come from? Did NAV generate it, or did something else? You neglected to include the rest of the e-mail sent by Django. Do your NAV webserver logs contain referrer information for the failing request?
Andreas took the discussion off-list, but we found the problem, so here's the executive summary:
Andreas has graphite-web 0.9.16 (or potentially, graphite-api 1.1.3), which apparently processes GET/POST arguments differently from 0.9.12.
A JavaScript component of IP Device Info uses jQuery to fetch data from Graphite, which results in a request using "bracket-syntax" for multi-valued arguments: I.e. it posts the equivalent of:
/graphite/render?target[]=metric.path.1&target[]=metric.path.2
The older graphite-web appears to handle this fine, while the newer only works with something like this:
/graphite/render?target=metric.path.1&target=metric.path.2
So NAV's request ends up with a newer graphite-web returning a 400 BAD REQUEST.
The latter way of making the request works with both graphite-web versions involved, so we've changed the way the requests are issued. The fix [1] will be in the next 4.8 bugfix release.
[1] https://github.com/UNINETT/nav/issues/1664
-
Andreas Dobloug -
Morten Brekkevold