OpenDataNode / open-data-node

Open Data Node
11 stars 3 forks source link

"Couldn't get pipelines, probably UnifiedViews is not responding." #213

Open jindrichmynarz opened 9 years ago

jindrichmynarz commented 9 years ago

When I try to associate a pipeline to a dataset in the internal catalogue, I go to "Pipelines" tab, click "Add pipeline" and select to add an existing pipeline "Couldn't get pipelines, probably UnifiedViews is not responding." error message is shown. UnifiedViews is running and responding, but it is slow and the query retrieve pipelines times out as can be seen in /var/log/apache2/odn-ckan-ic.error.log:

[Wed Sep 16 18:04:08 2015] [error] 2015-09-16 18:04:08,377 ERROR [ckanext] timed out
[Wed Sep 16 18:04:08 2015] [error] Traceback (most recent call last):
[Wed Sep 16 18:04:08 2015] [error]   File "/usr/share/python/odn-ckan-shared/lib/python2.7/site-packages/ckanext/pipeline/plugin.py", line 72, in get_all_pipelines
[Wed Sep 16 18:04:08 2015] [error]     pipes = uv_api.get_pipelines(user_external_id)
[Wed Sep 16 18:04:08 2015] [error]   File "/usr/share/python/odn-ckan-shared/lib/python2.7/site-packages/ckanext/pipeline/uv_helper.py", line 82, in get_pipelines
[Wed Sep 16 18:04:08 2015] [error]     return self._send_request(uv_url)
[Wed Sep 16 18:04:08 2015] [error]   File "/usr/share/python/odn-ckan-shared/lib/python2.7/site-packages/ckanext/pipeline/uv_helper.py", line 52, in _send_request
[Wed Sep 16 18:04:08 2015] [error]     response = urllib2.urlopen(request, timeout=TIMEOUT)
[Wed Sep 16 18:04:08 2015] [error]   File "/usr/lib/python2.7/urllib2.py", line 127, in urlopen
[Wed Sep 16 18:04:08 2015] [error]     return _opener.open(url, data, timeout)
[Wed Sep 16 18:04:08 2015] [error]   File "/usr/lib/python2.7/urllib2.py", line 401, in open
[Wed Sep 16 18:04:08 2015] [error]     response = self._open(req, data)
[Wed Sep 16 18:04:08 2015] [error]   File "/usr/lib/python2.7/urllib2.py", line 419, in _open
[Wed Sep 16 18:04:08 2015] [error]     '_open', req)
[Wed Sep 16 18:04:08 2015] [error]   File "/usr/lib/python2.7/urllib2.py", line 379, in _call_chain
[Wed Sep 16 18:04:08 2015] [error]     result = func(*args)
[Wed Sep 16 18:04:08 2015] [error]   File "/usr/lib/python2.7/urllib2.py", line 1211, in http_open
[Wed Sep 16 18:04:08 2015] [error]     return self.do_open(httplib.HTTPConnection, req)
[Wed Sep 16 18:04:08 2015] [error]   File "/usr/lib/python2.7/urllib2.py", line 1184, in do_open
[Wed Sep 16 18:04:08 2015] [error]     r = h.getresponse(buffering=True)
[Wed Sep 16 18:04:08 2015] [error]   File "/usr/lib/python2.7/httplib.py", line 1034, in getresponse
[Wed Sep 16 18:04:08 2015] [error]     response.begin()
[Wed Sep 16 18:04:08 2015] [error]   File "/usr/lib/python2.7/httplib.py", line 407, in begin
[Wed Sep 16 18:04:08 2015] [error]     version, status, reason = self._read_status()
[Wed Sep 16 18:04:08 2015] [error]   File "/usr/lib/python2.7/httplib.py", line 365, in _read_status
[Wed Sep 16 18:04:08 2015] [error]     line = self.fp.readline()
[Wed Sep 16 18:04:08 2015] [error]   File "/usr/lib/python2.7/socket.py", line 447, in readline
[Wed Sep 16 18:04:08 2015] [error]     data = self._sock.recv(self._rbufsize)
[Wed Sep 16 18:04:08 2015] [error] timeout: timed out
[Wed Sep 16 18:04:08 2015] [error] 2015-09-16 18:04:08,672 INFO  [ckan.lib.base]  /dataset/sk-36/pipelines/choose_pipeline render time 5.544 seconds

I have 86 pipelines in my instance of UnifiedViews and the instance runs on a beefy VM (64 GB RAM), so retrieving these pipelines should be swift. Ideally, this should be fixed in UnifiedViews. Alternatively, timeout could be extended in the CKAN plugin that calls the API of UnifiedViews.

Context: I'm using ODN 1.1.0.

skrchnavy commented 9 years ago

@jindrichmynarz do you have log from UV (master)?

jindrichmynarz commented 9 years ago

Do you mean /var/log/unifiedviews/backend/backend.log?

skrchnavy commented 9 years ago

master.log (in frontend), I am not sure where it is located.

jindrichmynarz commented 9 years ago

It is in /var/log/unifiedviews/frontend/master.log, but I cannot find anything related to this issue there. See here: https://gist.github.com/jindrichmynarz/effdbfb238fce38a3b2c.

mvi-eea-sk commented 9 years ago

@jindrichmynarz most probably the URL of UV (master) API is wrongly set.

In /etc/odn-simple/odn-ckan-ic/production.ini there should be something like this:

odn.uv.api.url = http://127.0.0.1:8080/master/api/1
odn.uv.timeout = 5
  1. Is UV (master) API running? Is it reachable?
  2. can you check if the url is correct (especially port)? Check if there is http or https.

    try: curl http://127.0.0.1:8080/master/api/1 <- url from cfg file

    should give proper UV api error (JSON):

    {
     "errorMessage":"human readable error, something like: unexpected error occured",
     "technicalMessage":"HTTP 404 Not Found"
    }
  3. try increasing the timeout
jindrichmynarz commented 9 years ago

I have http://127.0.0.1:28080/master/api/1 (note the different port) set as odn.uv.api.url in /etc/odn-simple/odn-ckan-ic/production.ini. Requesting this URL returns HTTP/1.1 404 Not Found.

mvi-eea-sk commented 9 years ago

if the response isn't JSON, the UV (master) API isn't running / reachable @Jan-Marcek can you help with this?

jindrichmynarz commented 9 years ago

If the UV API is not running, then it is weird that I can still associate pipelines to datasets in CKAN.

mvi-eea-sk commented 9 years ago

To associate pipeline you need the API function that threw time out error in the above log. Oh you mentioned you have 86 pipelines ... maybe just the API call, that retrieves the pipelines, last longer than 5 sec? Did you try increasing the timeout (odn.uv.timeout = 5)?

jindrichmynarz commented 9 years ago

My point is that if the API is not running, then it cannot throw timeout errors.

I think it is highly likely that the API call just takes longer than the timeout, as you say. For example, now I have lower load on UV and the requests no longer timeout.

mvi-eea-sk commented 9 years ago

@jindrichmynarz so whats the problem, increase the timeout in CKAN config file? @skrchnavy why is this assigned to me, this is clearly UV performance issue

jindrichmynarz commented 9 years ago

I think the problem is that this operation takes UV longer than it should. As you say, it is a UV performance issue.

skrchnavy commented 9 years ago

Reported in UnifiedViews/Core#531