Uploaded image for project: 'Help-Desk'
  1. Help-Desk
  2. HELP-7551

FIWARE.Request.Lab.Spain.FIWARE.WorkItem.Lab.Genoa.Node.Sanity.Check.Issues

        Details

          Description

          Hi,

          here to ask help about issues regarding FIWARE-Lab Genoa node sanity check fails, MAYBE related to an authorization with Keystone (please see here attached trace/logs already sent to Fernando Lopez)

          btw, see also:
          https://jira.fiware.org/browse/LAB-860
          https://jira.fiware.org/browse/LAB-860

          Thanks for your help
          regards
          giorgio

          ------------------------------------------------------

          After fiware-lab SSL reworks (maybe),
          genoa node sanity check fails:

          -------------------------------------------
          test_allocate_ip: unittest.case.SkipTest
          Details

          Errors: 2016-10-21 02:37:52,147 UTC - TestCase - ERROR - init_world(),
          failure in Nova: failed to get security group list: The server has
          either erred or is incapable of performing the requested operation.
          (HTTP 500) (Request-ID: req-4e17b43c-8d71-4320-a430-fe203124f3f0)
          2016-10-21 02:37:52,147 UTC - TestCase - ERROR - Fail with:
          cls.reset_world_sec_groups(world, suite)
          2016-10-21 02:38:52,632 UTC - TestCase - ERROR - init_world(), failure
          in Neutron: failed to get router list: <html><body><h1>504 Gateway
          Time-out</h1>
          The server didn't respond in time.
          </body></html>

          2016-10-21 02:38:52,633 UTC - TestCase - ERROR - Fail with:
          cls.reset_world_routers(world, suite)
          2016-10-21 02:39:22,754 UTC - TestCase - ERROR - init_world(), failure
          in Nova: failed to get allocated IP list: The server has either erred
          or is incapable of performing the requested operation. (HTTP 500)
          (Request-ID: req-17c7ed71-fd7c-4555-b828-7ce278798f20)
          2016-10-21 02:39:22,754 UTC - TestCase - ERROR - Fail with:
          cls.reset_world_allocated_ips(world, suite)
          2016-10-21 02:39:22,755 UTC - TestCase - ERROR - Fail in some reset_world

          Error in initialization phase: Error in initialization phase:
          resources from previous executions not released
          Traceback
          -------------------------------------------

          Now,
          If I run any openstack command,
          first time all run correctly (command completes immediately),
          afterward, if I run the command few second after, command hang going
          in timeout.

          As specified in previous mail
          (PLEASE READ log traces in previous mail, here below forwarded),
          I suspect authorization issue with internal Keystone APIs dialog (but
          maybe I'm wrong!).

          Any idea/suggestions about how to troubleshoouting ?

          btw, see also:
          https://jira.fiware.org/browse/LAB-860
          https://jira.fiware.org/browse/LAB-860

          btw, I know to be annoying asking you, but I do not know how to
          proceed elsewere.
          Please forward me if you can't help on this.

          Thanks for your patience!
          respect
          giorgio

          -------------------------------------------------------

          Giorgio Robino <giorgio.robino@cnit.it> ha scritto:

          [Nascondi Testo quotato]
          Hi Fernando!

          Central Keystone side, there is any known issue ?

          It seems to me that something wrong in keystone API calls (maybe after
          SSL certificate config?)
          e.g. if i run a "nova list" command, hi have keystone authorization issues,
          see log extracts here below.

          BTW, we didn't change outr configuration since two weeks ago.

          Any idea?
          thanks
          giorgio

          ----------------------------

          root@controller01:~# nova --debug list
          DEBUG (session:196) REQ: curl -g -i -X GET
          http://130.206.84.8:4730/v2.0/ -H "Accept: application/json" -H
          "User-Agent:
          python-keystoneclient"
          INFO (connectionpool:187) Starting new HTTP connection (1): 130.206.84.8
          DEBUG (connectionpool:353) "GET /v2.0/ HTTP/1.1" 200 422
          DEBUG (session:226) RESP: [200] date: Wed, 19 Oct 2016 08:01:49 GMT
          vary: X-Auth-Token content-length: 422 content-type
          : application/json
          RESP BODY: {"version": {"status": "stable", "updated":
          "2014-04-17T00:00:00Z", "media-types": [

          {"base": "application/js on", "type": "application/vnd.openstack.identity-v2.0+json"}

          ,

          {"base": "application/xml", "type": "application/vnd.open stack.identity-v2.0+xml"}

          ], "id": "v2.0", "links": [

          {"href": "http://130.206.84.8:4730/v2.0/", "rel": "self"}

          ,

          {"href": "http://docs.openstack.org/", "type": "text/html", "rel": "describedby"}

          ]}}

          DEBUG (v2:76) Making authentication request to
          http://130.206.84.8:4730/v2.0/tokens
          DEBUG (connectionpool:353) "POST /v2.0/tokens HTTP/1.1" 200 58933
          DEBUG (iso8601:184) Parsed 2016-10-20T08:01:50Z into

          {'tz_sign': None, 'second_fraction': None, 'hour': u'08', 'daydash ': u'20', 'tz_hour': None, 'month': None, 'timezone': u'Z', 'second': u'50', 'tz_minute': None, 'year': u'2016', 'separ ator': u'T', 'monthdash': u'10', 'day': None, 'minute': u'01'}

          with default timezone
          <iso8601.iso8601.Utc object at 0x7
          f5fc3b5e590>
          DEBUG (iso8601:140) Got u'2016' for 'year' with default None
          DEBUG (iso8601:140) Got u'10' for 'monthdash' with default 1
          DEBUG (iso8601:140) Got 10 for 'month' with default 10
          DEBUG (iso8601:140) Got u'20' for 'daydash' with default 1
          DEBUG (iso8601:140) Got 20 for 'day' with default 20
          DEBUG (iso8601:140) Got u'08' for 'hour' with default None
          DEBUG (iso8601:140) Got u'01' for 'minute' with default None
          DEBUG (iso8601:140) Got u'50' for 'second' with default None
          DEBUG (session:196) REQ: curl -g -i -X GET
          http://130.251.135.65:8774/v2/00000000000003228460960090160000/servers/detai

          l -H "User-Agent: python-novaclient" -H "Accept: application/json" -H
          "X-Auth-Token:

          {SHA1}19977550164b85ca6dfc57816e53
          1cc4514a1689"
          INFO (connectionpool:187) Starting new HTTP connection (1): 130.251.135.65
          DEBUG (connectionpool:353) "GET
          /v2/00000000000003228460960090160000/servers/detail HTTP/1.1" 401 23
          DEBUG (session:226) RESP:
          DEBUG (v2:76) Making authentication request to
          http://130.206.84.8:4730/v2.0/tokens
          INFO (connectionpool:222) Resetting dropped connection: 130.206.84.8
          DEBUG (connectionpool:353) "POST /v2.0/tokens HTTP/1.1" 200 58933
          INFO (connectionpool:222) Resetting dropped connection: 130.251.135.65
          DEBUG (connectionpool:353) "GET
          /v2/00000000000003228460960090160000/servers/detail HTTP/1.1" 500 128
          DEBUG (session:226) RESP:
          DEBUG (shell:911) The server has either erred or is incapable of
          performing the requested operation. (HTTP 500) (Request-ID:
          req-90791e10-7506-424b-821e
          -364ab557e8b5)
          Traceback (most recent call last):
          File "/usr/lib/python2.7/dist-packages/novaclient/shell.py", line
          908, in main
          OpenStackComputeShell().main(argv)
          File "/usr/lib/python2.7/dist-packages/novaclient/shell.py", line
          835, in main
          args.func(self.cs, args)
          File "/usr/lib/python2.7/dist-packages/novaclient/v2/shell.py",
          line 1377, in do_list
          sort_dirs=sort_dirs)
          File "/usr/lib/python2.7/dist-packages/novaclient/v2/servers.py",
          line 594, in list
          return self._list("/servers%s%s" % (detail, query_string), "servers")
          File "/usr/lib/python2.7/dist-packages/novaclient/base.py", line
          64, in _list
          _resp, body = self.api.client.get(url)
          File "/usr/lib/python2.7/dist-packages/keystoneclient/adapter.py",
          line 170, in get
          return self.request(url, 'GET', **kwargs)
          File "/usr/lib/python2.7/dist-packages/novaclient/client.py", line
          92, in request
          raise exceptions.from_response(resp, body, url, method)
          ClientException: The server has either erred or is incapable of
          performing the requested operation. (HTTP 500) (Request-ID:
          req-90791e10-7506-424b-821e-
          364ab557e8b5)
          ERROR (ClientException): The server has either erred or is incapable
          of performing the requested operation. (HTTP 500) (Request-ID:
          req-90791e10-7506-42
          4b-821e-364ab557e8b5)


          ----------------------------
          /var/log/nova/nova-api.log

          2016-10-19 08:04:29.100 8439 DEBUG keystoneclient.session [-] REQ:
          curl -g -i -X GET http://130.206.84.8:4731/v3/auth/tokens -H
          "X-Subject-Token: {SHA1}

          da1cb5c57ad020ce3c457707e22b963b1cd872e0" -H
          "User-Agent: python-keystoneclient" -H "Accept: application/json" -H
          "X-Auth-Token:

          {SHA1}

          c26ecbdfc94d27f7be18c363453490bb9fb2f240"
          _http_log_request
          /usr/lib/python2.7/dist-packages/keystoneclient/session.py:196
          2016-10-19 08:04:29.141 8433 ERROR nova.api.openstack
          [req-90791e10-7506-424b-821e-364ab557e8b5 admin-genoa
          00000000000003228460960090160000 - - -] Caught error: Request to
          http://172.18.0.2:9696/v2.0/ports.json?device_id=ba151850-22c8-4689-911b-d7c4aa82b4dc&device_id=ca9689da-37d2-4e65-b782-d7a899318a1a timed out
          (HTTP
          408)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack Traceback (most
          recent call last):
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/nova/api/openstack/_init_.py",
          line 125, in _call_
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack return
          req.get_response(self.application)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/webob/request.py", line 1320, in send
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack application,
          catch_exc_info=False)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/webob/request.py", line 1284, in
          call_application
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack app_iter =
          application(self.environ, start_response)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in _call_
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack return
          resp(environ, start_response)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/_init_.py",
          line 634, in _call_
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack return
          self._call_app(env, start_response)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/_init_.py",
          line 554, in _call_app
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack return
          self._app(env, _fake_start_response)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in _call_
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack return
          resp(environ, start_response)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in _call_
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack return
          resp(environ, start_response)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/local/lib/python2.7/dist-packages/routes/middleware.py", line
          141, in _call_
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack response =
          self.app(environ, start_response)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/webob/dec.py", line 144, in _call_
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack return
          resp(environ, start_response)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/webob/dec.py", line 130, in _call_
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack resp =
          self.call_func(req, *args, **self.kwargs)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/webob/dec.py", line 195, in call_func
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack return
          self.func(req, *args, **kwargs)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py", line
          756, in _call_
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack
          content_type, body, accept)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py", line
          847, in _process_stack
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack request,
          action_args)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py", line
          710, in post_process_extensions
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack **action_args)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/nova/api/openstack/compute/contrib/security_groups.py", line 471,
          in
          detail
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack
          self._extend_servers(req, list(resp_obj.obj['servers']))
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/nova/api/openstack/compute/contrib/security_groups.py", line 422,
          in
          _extend_servers
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack servers))
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/nova/network/security_group/neutron_driver.py", line 366,
          in
          get_instances_security_groups_bindings
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack ports =
          self._get_ports_from_server_list(servers, neutron)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/nova/network/security_group/neutron_driver.py", line 325,
          in
          _get_ports_from_server_list
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack
          ports.extend(neutron.list_ports(**search_opts).get('ports'))
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
          102, in with_params
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack ret =
          self.function(instance, *args, **kwargs)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
          534, in list_ports
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack **_params)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
          307, in list
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack for r in
          self._pagination(collection, path, **params):
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
          320, in _pagination
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack res =
          self.get(path, params=params)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
          293, in get
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack
          headers=headers, params=params)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
          270, in retry_request
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack
          headers=headers, params=params)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/neutronclient/v2_0/client.py", line
          200, in do_request
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack
          content_type=self.content_type())
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/neutronclient/client.py", line 306,
          in do_request
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack return
          self.request(url, method, **kwargs)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/neutronclient/client.py", line 294,
          in request
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack resp =
          super(SessionClient, self).request(*args, **kwargs)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/keystoneclient/adapter.py", line 95,
          in request
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack return
          self.session.request(url, method, **kwargs)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/keystoneclient/utils.py", line 318,
          in inner
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack return
          func(*args, **kwargs)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/keystoneclient/session.py", line
          384, in request
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack resp =
          send(**kwargs)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack File
          "/usr/lib/python2.7/dist-packages/keystoneclient/session.py", line
          425, in _send_request
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack raise
          exceptions.RequestTimeout(msg)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack RequestTimeout:
          Request to
          http://172.18.0.2:9696/v2.0/ports.json?device_id=ba151850-22c8-4689-911b-d7c4aa82b4dc&device_id=ca9689da-37d2-4e65-b782-d7a899318a1a timed out
          (HTTP
          408)
          2016-10-19 08:04:29.141 8433 TRACE nova.api.openstack
          2016-10-19 08:04:29.146 8433 INFO nova.api.openstack
          [req-90791e10-7506-424b-821e-364ab557e8b5 admin-genoa
          00000000000003228460960090160000 - - -]
          http://130.251.135.65:8774/v2/00000000000003228460960090160000/servers/detail
          returned with HTTP 500
          2016-10-19 08:04:29.148 8433 DEBUG nova.api.openstack.wsgi
          [req-90791e10-7506-424b-821e-364ab557e8b5 admin-genoa
          00000000000003228460960090160000 - - -] Returning 500 to user: The
          server has either erred or is incapable of performing the requested
          operation. _call_
          /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:1166
          2016-10-19 08:04:29.149 8433 INFO nova.osapi_compute.wsgi.server
          [req-90791e10-7506-424b-821e-364ab557e8b5 admin-genoa
          00000000000003228460960090160000 - - -] 172.18.0.11 "GET
          /v2/00000000000003228460960090160000/servers/detail HTTP/1.1" status:
          500 len: 354 time: 30.3907800
          2016-10-19 08:04:29.230 8439 DEBUG keystoneclient.session [-] RESP:
          _http_log_response
          /usr/lib/python2.7/dist-packages/keystoneclient/session.py:226
          2016-10-19 08:04:29.230 8439 DEBUG keystoneclient.session [-] Request
          returned failure status: 404 request
          /usr/lib/python2.7/dist-packages/keystoneclient/session.py:398
          2016-10-19 08:04:29.231 8439 WARNING keystonemiddleware.auth_token [-]
          Authorization failed for token
          2016-10-19 08:04:29.231 8439 WARNING keystonemiddleware.auth_token [-]
          Identity response: {"error": {"message": "Could not find token:
          8660895fc7034c8aaa93ae868ae2d0c9", "code": 404, "title": "Not Found"}}
          2016-10-19 08:04:29.232 8439 WARNING keystonemiddleware.auth_token [-]
          Authorization failed for token
          2016-10-19 08:04:29.235 8439 INFO nova.osapi_compute.wsgi.server [-]
          172.18.0.11 "GET /v2/0595b850bd2d44fa8911d488f7c27c96/images/detail
          HTTP/1.1" status: 401 len: 278 time: 0.1447031
          2016-10-19 08:04:29.236 8428 DEBUG nova.api.openstack.wsgi [-] Calling
          method '<bound method Versions.index of
          <nova.api.openstack.compute.versions.Versions object at
          0x7f5330d36490>>' _process_stack
          /usr/lib/python2.7/dist-packages/nova/api/openstack/wsgi.py:783
          ----------------------------

            Issue Links

            relates to

            extRequest - Request from external stakeholder received in the help desk HELP-7566 FIWARE.Request.Lab.FIWARE.telefonica.network.IP.filtered.

            • Major - Major loss of function.
            • Closed

              Activity

                People

                • Assignee:
                  jicg José Ignacio Carretero Guarde
                  Reporter:
                  tntlab Genoa Node Support Team
                • Votes:
                  0 Vote for this issue
                  Watchers:
                  3 Start watching this issue

                  Dates

                  • Created:
                    Updated:
                    Resolved: