Juniper Openstack

[3.1 29] UI: 'Error: Internal Server Error' seen on few pages on monitor and charts not loading

Series r3.1
Bug #1616797

Bug #1616797 reported by Pavana on 2016-08-25

This bug affects 1 person

	Status	Importance	Assigned to	Milestone
Juniper Openstack	Status tracked in Trunk
R3.0	Fix Committed	High	Pavana	Juniper Openstack r3.0.3.0
R3.1	Fix Committed	High	Pavana	Juniper Openstack r3.1.1.0
Trunk	Fix Committed	High	Pavana	Juniper Openstack r3.2.0.0-fcs "r3.2.0.0"

Bug Description

Upgraded my single node setup to R3.1 build 29 mitaka and installed docker and no other config/installation was done.

On Monitor > Infrastructure > Control Nodes -
Warning - 'Error: Internal Server Error'
Chart not loaded
Seen on console -
jquery-1.8.3.min.js?built_at=1472037282:2 POST https://nodeg1:8143/api/admin/reports/query 500 (Internal Server Error)

On Monitor > Infrastructure > Analytics Nodes -
Warning - 'Error: Internal Server Error'
Chart not loaded
Seen on console -
jquery-1.8.3.min.js?built_at=1472037282:2 POST https://nodeg1:8143/api/admin/reports/query 500 (Internal Server Error)send @ jquery-1.8.3.min.js?built_at=1472037282:2ajax @ jquery-1.8.3.min.js?built_at=1472037282:2Contrail.ajaxHandler @ nonamd.libs.js?built_at=1472037282:7143initVLRequests @ core.bundle.js?built_at=1472037282:2665pSuccessHandler @ core.bundle.js?built_at=1472037282:2561(anonymous function) @ nonamd.libs.js?built_at=1472037282:7144l @ jquery-1.8.3.min.js?built_at=1472037282:2fireWith @ jquery-1.8.3.min.js?built_at=1472037282:2T @ jquery-1.8.3.min.js?built_at=1472037282:2r @ jquery-1.8.3.min.js?built_at=1472037282:2
jquery-1.8.3.min.js?built_at=1472037282:2 POST https://nodeg1:8143/api/tenant/get-data 500 (Internal Server Error)send @ jquery-1.8.3.min.js?built_at=1472037282:2ajax @ jquery-1.8.3.min.js?built_at=1472037282:2Contrail.ajaxHandler @ nonamd.libs.js?built_at=1472037282:7143initVLRequests @ core.bundle.js?built_at=1472037282:2665pSuccessHandler @ core.bundle.js?built_at=1472037282:2561(anonymous function) @ nonamd.libs.js?built_at=1472037282:7144l @ jquery-1.8.3.min.js?built_at=1472037282:2fireWith @ jquery-1.8.3.min.js?built_at=1472037282:2T @ jquery-1.8.3.min.js?built_at=1472037282:2r @ jquery-1.8.3.min.js?built_at=1472037282:2
jquery-1.8.3.min.js?built_at=1472037282:2 POST https://nodeg1:8143/api/qe/query 500 (Internal Server Error)send @ jquery-1.8.3.min.js?built_at=1472037282:2ajax @ jquery-1.8.3.min.js?built_at=1472037282:2Contrail.ajaxHandler @ nonamd.libs.js?built_at=1472037282:7143fetchPrimaryData @ core.bundle.js?built_at=1472037282:2640ContrailRemoteDataHandler @ core.bundle.js?built_at=1472037282:2521createRemoteDataHandler @ core.bundle.js?built_at=1472037282:2819ContrailListModel @ core.bundle.js?built_at=1472037282:2808AnalyticsNodeQueriesModel @ AnalyticsNodeQueriesModel.js?built_at=1472037282:42(anonymous function) @ AnalyticsNodesSummaryChartsView.js?built_at=1472037282:40Event.notify @ jquery.dep.libs.js?built_at=1472037282:2674refresh @ jquery.dep.libs.js?built_at=1472037282:4034endUpdate @ jquery.dep.libs.js?built_at=1472037282:3269setData @ core.bundle.js?built_at=1472037282:2878completeCallback @ core.bundle.js?built_at=1472037282:3170vlCompleteHandler @ core.bundle.js?built_at=1472037282:2528updateVLRequestStatus @ core.bundle.js?built_at=1472037282:2713(anonymous function) @ core.bundle.js?built_at=1472037282:2699(anonymous function) @ nonamd.libs.js?built_at=1472037282:7150l @ jquery-1.8.3.min.js?built_at=1472037282:2fireWith @ jquery-1.8.3.min.js?built_at=1472037282:2T @ jquery-1.8.3.min.js?built_at=1472037282:2r @ jquery-1.8.3.min.js?built_at=1472037282:2
jquery-1.8.3.min.js?built_at=1472037282:2 POST https://nodeg1:8143/api/qe/query 500 (Internal Server Error)send @ jquery-1.8.3.min.js?built_at=1472037282:2ajax @ jquery-1.8.3.min.js?built_at=1472037282:2Contrail.ajaxHandler @ nonamd.libs.js?built_at=1472037282:7143fetchPrimaryData @ core.bundle.js?built_at=1472037282:2640ContrailRemoteDataHandler @ core.bundle.js?built_at=1472037282:2521createRemoteDataHandler @ core.bundle.js?built_at=1472037282:2819ContrailListModel @ core.bundle.js?built_at=1472037282:2808DatabaseUsageModel @ DatabaseUsageModel.js?built_at=1472037282:47(anonymous function) @ AnalyticsNodesSummaryChartsView.js?built_at=1472037282:41Event.notify @ jquery.dep.libs.js?built_at=1472037282:2674refresh @ jquery.dep.libs.js?built_at=1472037282:4034endUpdate @ jquery.dep.libs.js?built_at=1472037282:3269setData @ core.bundle.js?built_at=1472037282:2878completeCallback @ core.bundle.js?built_at=1472037282:3170vlCompleteHandler @ core.bundle.js?built_at=1472037282:2528updateVLRequestStatus @ core.bundle.js?built_at=1472037282:2713(anonymous function) @ core.bundle.js?built_at=1472037282:2699(anonymous function) @ nonamd.libs.js?built_at=1472037282:7150l @ jquery-1.8.3.min.js?built_at=1472037282:2fireWith @ jquery-1.8.3.min.js?built_at=1472037282:2T @ jquery-1.8.3.min.js?built_at=1472037282:2r @ jquery-1.8.3.min.js?built_at=1472037282:2
jquery-1.8.3.min.js?built_at=1472037282:2 POST https://nodeg1:8143/api/qe/query 500 (Internal Server Error)

Now configured a VN and VM which went through fine.
On Monitor > Networking > Dashboard :
Message - No Networks Found.
Chart not loaded and says 'Error in getting data.'
Seen on console -
jquery-1.8.3.min.js?built_at=1472037282:2 GET https://nodeg1:8143/api/tenant/monitoring/project-connected-graph?fqName=default-domain:admin&_=1472112798752 net::ERR_EMPTY_RESPONSEsend @ jquery-1.8.3.min.js?built_at=1472037282:2ajax @ jquery-1.8.3.min.js?built_at=1472037282:2Contrail.ajaxHandler @ nonamd.libs.js?built_at=1472037282:7143fetchPrimaryData @ core.bundle.js?built_at=1472037282:2640ContrailRemoteDataHandler @ core.bundle.js?built_at=1472037282:2521fetchData @ ContrailGraphModel.js?built_at=1472037282:52render @ GraphView.js?built_at=1472037282:65renderConnectedGraph @ nm.module.js?built_at=1472037282:1768render @ nm.module.js?built_at=1472037282:1727(anonymous function) @ controller.init.js?built_at=1472037282:2653execCb @ require.js:29check @ require.js:18enable @ require.js:23init @ require.js:17(anonymous function) @ require.js:26
jquery-1.8.3.min.js?built_at=1472037282:2 GET https://nodeg1:8143/api/tenant/monitoring/project-config-graph?fqName=default-domain:admin&_=1472112798796 net::ERR_EMPTY_RESPONSEsend @ jquery-1.8.3.min.js?built_at=1472037282:2ajax @ jquery-1.8.3.min.js?built_at=1472037282:2Contrail.ajaxHandler @ nonamd.libs.js?built_at=1472037282:7143fetchPrimaryData @ core.bundle.js?built_at=1472037282:2640ContrailRemoteDataHandler @ core.bundle.js?built_at=1472037282:2521fetchData @ ContrailGraphModel.js?built_at=1472037282:52render @ GraphView.js?built_at=1472037282:65renderConfigGraph @ nm.module.js?built_at=1472037282:1799render @ nm.module.js?built_at=1472037282:1730(anonymous function) @ controller.init.js?built_at=1472037282:2653execCb @ require.js:29check @ require.js:18enable @ require.js:23init @ require.js:17(anonymous function) @ require.js:26
jquery-1.8.3.min.js?built_at=1472037282:2 POST https://nodeg1:8143/api/tenant/networking/virtual-networks/details?count=10&nextCount=100&fqn=default-domain:admin&startAt=1472112798840 net::ERR_EMPTY_RESPONSE

root@nodeg1:~# contrail-status
== Contrail vRouter ==
supervisor-vrouter: active
contrail-vrouter-agent active
contrail-vrouter-nodemgr active

== Contrail Control ==
supervisor-control: active
contrail-control active
contrail-control-nodemgr active
contrail-dns active
contrail-named active

== Contrail Analytics ==
supervisor-analytics: active
contrail-alarm-gen active
contrail-analytics-api active
contrail-analytics-nodemgr active
contrail-collector active
contrail-query-engine active
contrail-snmp-collector active
contrail-topology active

== Contrail Config ==
supervisor-config: active
contrail-api:0 active
contrail-config-nodemgr active
contrail-device-manager active
contrail-discovery:0 active
contrail-schema active
contrail-svc-monitor active
ifmap active

== Contrail Web UI ==
supervisor-webui: active
contrail-webui active
contrail-webui-middleware active

== Contrail Database ==
contrail-database: active

== Contrail Supervisor Database ==
supervisor-database: active
contrail-database-nodemgr active
kafka active

== Contrail Support Services ==
supervisor-support-service: active
rabbitmq-server active

contrail-webui-stdout.log -

08/25/2016 01:12:51 PM - ^[[34mdebug^[[39m: We got the channel:df0141e8-1cc0-4574-89e3-9eff9103b7a6 by process:27492
08/25/2016 01:12:51 PM - ^[[34mdebug^[[39m: Query Request: {"pageSize":10000,"page":1,"tgUnits":"secs","fromTimeUTC":"now-15m","toTimeUTC":"now","async":true,"queryId":"154A0E8C-5D88-47DA-A9D6-F631F45F5D0F-1472110971045","reRunTimeRange":600,"select":"Source, name, T, cpu_info.cpu_share, cpu_info.mem_res","groupFields":["Source"],"plotFields":["cpu_info.cpu_share"],"table":"StatTable.ComputeCpuState.cpu_info","where":""}
08/25/2016 01:12:51 PM - ^[[34mdebug^[[39m: Query sent to Opserver at Thu Aug 25 2016 13:12:51 GMT+0530 (IST) {"table":"StatTable.ComputeCpuState.cpu_info","start_time":"now-15m","end_time":"now","select_fields":["Source","name","T","cpu_info.cpu_share","cpu_info.mem_res"],"filter":[],"limit":150000,"where":[[{"name":"name","value":"","op":7}]]}
08/25/2016 01:12:51 PM - ^[[31merror^[[39m: URL [http://10.204.217.41:8081/analytics/query] returned error ["Internal Server Error"]
08/25/2016 01:12:51 PM - ^[[31merror^[[39m: Error Run Query: REST Server Error: Internal Server Error
    at APIServer.retryMakeCall (/usr/src/contrail/contrail-web-core/src/serverroot/common/rest.api.js:203:13)
    at Request.<anonymous> (/usr/src/contrail/contrail-web-core/src/serverroot/common/rest.api.js:336:18)
    at Request.emit (events.js:98:17)
    at Request.mixin._fireSuccess (/usr/lib64/node_modules/restler/lib/restler.js:226:10)
    at /usr/lib64/node_modules/restler/lib/restler.js:157:20
    at IncomingMessage.parsers.auto (/usr/lib64/node_modules/restler/lib/restler.js:390:7)
    at Request.mixin._encode (/usr/lib64/node_modules/restler/lib/restler.js:194:29)
    at /usr/lib64/node_modules/restler/lib/restler.js:153:16
    at Request.mixin._decode (/usr/lib64/node_modules/restler/lib/restler.js:169:7)
    at IncomingMessage.<anonymous> (/usr/lib64/node_modules/restler/lib/restler.js:146:14)
08/25/2016 01:12:51 PM - ^[[31merror^[[39m: REST Server Error: Internal Server Error
    at APIServer.retryMakeCall (/usr/src/contrail/contrail-web-core/src/serverroot/common/rest.api.js:203:13)
    at Request.<anonymous> (/usr/src/contrail/contrail-web-core/src/serverroot/common/rest.api.js:336:18)
    at Request.emit (events.js:98:17)
    at Request.mixin._fireSuccess (/usr/lib64/node_modules/restler/lib/restler.js:226:10)
    at /usr/lib64/node_modules/restler/lib/restler.js:157:20
    at IncomingMessage.parsers.auto (/usr/lib64/node_modules/restler/lib/restler.js:390:7)
    at Request.mixin._encode (/usr/lib64/node_modules/restler/lib/restler.js:194:29)
    at /usr/lib64/node_modules/restler/lib/restler.js:153:16
    at Request.mixin._decode (/usr/lib64/node_modules/restler/lib/restler.js:169:7)
    at IncomingMessage.<anonymous> (/usr/lib64/node_modules/restler/lib/restler.js:146:14)

contrail-control-nodemgr-stderr.log -
08/25/2016 11:45:01 AM [contrail-control-nodemgr]: Processing event[EvSandeshUVESend] in state[Disconnect]
08/25/2016 11:45:01 AM [contrail-control-nodemgr]: SANDESH: [DROP: WrongClientSMState] NodeStatusUVE: data = << name = nodeg1 disk_usage_info = { /dev/mapper/nodeg1--vg-root : << partition_type = ext4 partition_space_used_1k = 16880524 partition_space_available_1k = 60929648 percentage_partition_space_used = 22 >>/dev/sda1 : << partition_type = ext2 partition_space_used_1k = 68782 partition_space_available_1k = 159749 percentage_partition_space_used = 30 >> } process_mem_cpu_usage = { contrail-control : << mem_virt = 522544 cpu_share = 0.02 mem_res = 15264 >>contrail-control-nodemgr : << mem_virt = 170276 cpu_share = 0.02 mem_res = 29772 >>contrail-dns : << mem_virt = 516992 cpu_share = 0.02 mem_res = 14580 >>contrail-named : << mem_virt = 352196 cpu_share = 0.0 mem_res = 16692 >> } system_mem_cpu_usage = << mem_info = << total = 32659240 used = 17386068 free = 15273172 buffers = 118068 cached = 1493760 >> cpu_load = << one_min_avg = 5.26 five_min_avg = 2.33 fifteen_min_avg = 0.86 >> cpu_share = 10.21 >> >>
08/25/2016 11:45:01 AM [contrail-control-nodemgr]: Discarding event[EvSandeshUVESend] in state[Disconnect]
08/25/2016 11:45:12 AM [contrail-control-nodemgr]: Received discovery update [{u'partcount': u'{ "1":[0,1], "2":[1,3], "3":[4,8], "4":[12,8], "5":[20,10]}', u'@publisher-id': u'nodeg1', u'pid': u'2524', u'ip-address': u'10.204.217.41', u'redis-gen': u'1', u'port': u'8086'}] for collector service
08/25/2016 11:45:12 AM [contrail-control-nodemgr]: Processing event[EvCollectorChange] in state[Disconnect]
08/25/2016 11:45:12 AM [contrail-control-nodemgr]: Session Event: TCP Connected
08/25/2016 11:45:12 AM [contrail-control-nodemgr]: Sandesh Client: Event[EvCollectorChange] => State[Disconnect] -> State[Connect]
08/25/2016 11:45:12 AM [contrail-control-nodemgr]: Processing event[EvSandeshUVESend] in state[Connect]
08/25/2016 11:45:12 AM [contrail-control-nodemgr]: SANDESH: [DROP: WrongClientSMState] NodeStatusUVE: data = << name = nodeg1 process_status = [ << module_id = contrail-control-nodemgr instance_id = 0 state = Non-Functional connection_infos = [ << type = Collector name = server_addrs = [ 10.204.217.41:8086, ] status = Initializing description = Disconnect to Connect on EvCollectorChange >>, << type = Discovery name = Collector server_addrs = [ 10.204.217.41:5998, ] status = Up description = Subscribe Response >>, ] description = Collector connection down >>, ] >>
08/25/2016 11:45:12 AM [contrail-control-nodemgr]: Discarding event[EvSandeshUVESend] in state[Connect]
08/25/2016 11:45:12 AM [contrail-control-nodemgr]: Processing event[EvTcpConnected] in state[Connect]
08/25/2016 11:45:12 AM [contrail-control-nodemgr]: Sandesh Client: Event[EvTcpConnected] => State[Connect] -> State[ClientInit]
08/25/2016 11:45:12 AM [contrail-control-nodemgr]: Processing event[EvSandeshUVESend] in state[ClientInit]
08/25/2016 11:45:12 AM [contrail-control-nodemgr]: Processing event[EvSandeshUVESend] in state[ClientInit]
08/25/2016 11:45:12 AM [contrail-control-nodemgr]: Processing event[EvSandeshCtrlMessageRecv] in state[ClientInit]
08/25/2016 11:45:12 AM [contrail-control-nodemgr]: Sandesh Client: Event[EvSandeshCtrlMessageRecv] => State[ClientInit] -> State[Established]
wokeup and found a line
Exception AssertionError: AssertionError() in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored
Exception AssertionError: AssertionError() in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored
Exception AssertionError: AssertionError() in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored
Exception AssertionError: AssertionError() in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored
Exception AssertionError: AssertionError() in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored
Exception AssertionError: AssertionError() in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored
Exception AssertionError: AssertionError() in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored
Exception AssertionError: AssertionError() in <module 'threading' from '/usr/lib/python2.7/threading.pyc'> ignored
wokeup and found a line

Screenshot attached.

Tags:

Revision history for this message

Pavana (pavanap) wrote on 2016-08-25:

Screen Shot 2016-08-25 at 1.35.56 PM.png Edit (150.7 KiB, image/png)

information type:

Proprietary → Public

Revision history for this message

Nikhil Bansal (nikhilb-u) wrote on 2016-08-25:

There are couple of issues here.
1. in obj_perms function of vnc_api, this code was added:
            finally:
            del self._headers['X-USER-TOKEN']
   however, if request_server gets 401 error then self._headers get overwritten
            if ((status == 401) and (not self._auth_token_input) and (not retry_after_authn)):
                self._headers = self._authenticate(content, self._headers)
   due to this we get following error:
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/bottle.py", line 856, in _handle
    return route.call(**args)
  File "/usr/lib/python2.7/dist-packages/bottle.py", line 1721, in wrapper
    rv = callback(*a, **ka)
  File "/usr/lib/python2.7/dist-packages/opserver/opserver.py", line 411, in _impl
    self._vnc_api_client.is_role_cloud_admin(user_token):
  File "/usr/lib/python2.7/dist-packages/opserver/vnc_cfg_api_client.py", line 61, in is_role_cloud_admin
    result = self._get_user_token_info(user_token)
  File "/usr/lib/python2.7/dist-packages/opserver/vnc_cfg_api_client.py", line 30, in _get_user_token_info
    return self._vnc_api_client.obj_perms(user_token)
  File "/usr/lib/python2.7/dist-packages/vnc_api/vnc_api.py", line 1208, in obj_perms
    rv = None
KeyError: 'X-USER-TOKEN'

2. There is intermittent authentication issue also which somehow went away after couple of analytics restart that I did to verify first issue.

VishnuVardhan V (vishnuvv) on 2016-08-25

tags:

added: analytics

Revision history for this message

Megh Bhatt (meghb) wrote on 2016-08-25:

Download full text (5.1 KiB)

It seems that bunch of requests from contrail-analytics-api VNC api client to keystone at around 12:52:40 are missing from keystone logs.

contrail-analytics-api logs
--------------------------------------

Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/bottle.py", line 856, in _handle
    return route.call(**args)
  File "/usr/lib/python2.7/dist-packages/bottle.py", line 1721, in wrapper
    rv = callback(*a, **ka)
  File "/usr/lib/python2.7/dist-packages/opserver/opserver.py", line 411, in _impl
    self._vnc_api_client.is_role_cloud_admin(user_token):
  File "/usr/lib/python2.7/dist-packages/opserver/vnc_cfg_api_client.py", line 61, in is_role_cloud_admin
    result = self._get_user_token_info(user_token)
  File "/usr/lib/python2.7/dist-packages/opserver/vnc_cfg_api_client.py", line 30, in _get_user_token_info
    return self._vnc_api_client.obj_perms(user_token)
  File "/usr/lib/python2.7/dist-packages/vnc_api/vnc_api.py", line 1208, in obj_perms
    del self._headers['X-USER-TOKEN']
KeyError: 'X-USER-TOKEN'
10.204.217.41 - - [2016-08-25 12:52:40] "POST /analytics/uves/database-node HTTP/1.1" 500 156 0.032620
10.204.217.41 - - [2016-08-25 12:52:40] "POST /analytics/uves/analytics-node HTTP/1.1" 200 10437 0.037467
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/bottle.py", line 856, in _handle
    return route.call(**args)
  File "/usr/lib/python2.7/dist-packages/bottle.py", line 1721, in wrapper
    rv = callback(*a, **ka)
  File "/usr/lib/python2.7/dist-packages/opserver/opserver.py", line 411, in _impl
    self._vnc_api_client.is_role_cloud_admin(user_token):
  File "/usr/lib/python2.7/dist-packages/opserver/vnc_cfg_api_client.py", line 61, in is_role_cloud_admin
    result = self._get_user_token_info(user_token)
  File "/usr/lib/python2.7/dist-packages/opserver/vnc_cfg_api_client.py", line 30, in _get_user_token_info
    return self._vnc_api_client.obj_perms(user_token)
  File "/usr/lib/python2.7/dist-packages/vnc_api/vnc_api.py", line 1208, in obj_perms
    del self._headers['X-USER-TOKEN']
KeyError: 'X-USER-TOKEN'
10.204.217.41 - - [2016-08-25 12:52:40] "POST /analytics/uves/config-node HTTP/1.1" 500 156 0.037808
10.204.217.41 - - [2016-08-25 12:52:40] "POST /analytics/uves/control-node HTTP/1.1" 200 4659 0.026998
10.204.217.41 - - [2016-08-25 12:52:40] "GET /analytics/uves/virtual-networks?cfilt=UveVirtualNetworkAgent HTTP/1.1" 200 243 0.015646
Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/bottle.py", line 856, in _handle
    return route.call(**args)
  File "/usr/lib/python2.7/dist-packages/bottle.py", line 1721, in wrapper
    rv = callback(*a, **ka)
  File "/usr/lib/python2.7/dist-packages/opserver/opserver.py", line 411, in _impl
    self._vnc_api_client.is_role_cloud_admin(user_token):
  File "/usr/lib/python2.7/dist-packages/opserver/vnc_cfg_api_client.py", line 61, in is_role_cloud_admin
    result = self._get_user_token_info(user_token)
  File "/usr/lib/python2.7/dist-packages/opserver/vnc_cfg_api_client.py", line 30, in _get_user_token_info
    return self._vnc_api_client.obj_perms(user_token)
  File "/usr/lib/python2.7/dist-packages/vnc_...

It seems that bunch of requests from contrail-analytics-api VNC api client to keystone at around 12:52:40 are missing from keystone logs.

contrail-analytics-api logs
--------------------------------------

keystone logs
-------------------

2016-08-25 12:52:39.487 4381 INFO eventlet.wsgi.server [req-52eae439-bb84-4291-8648-9502e4bd93c0 a8f8e869d40b4ea2a5df2c2c79388d41 c683a111eeb1423b8fb24a634f525035 - default default] 10.204.217.41 - - [25/Aug/2016 12:52:39] "GET /v3/auth/tokens HTTP/1.1" 200 6486 0.100954
2016-08-25 12:53:10.135 4380 INFO keystone.common.wsgi [req-c6a89140-29cf-44e3-b740-a03702ac7805 - - - - -] POST http://10.204.217.41:35357/v2.0/tokens

It doesn't look like keystone was restarted at that time

root@nodeg1:/var/log/contrail# supervisorctl -s unix:///var/run/supervisord_openstack.sock
barbican-api                     FATAL      Exited too quickly (process log may have details)
barbican-worker                  RUNNING    pid 2541, uptime 11:22:18
cinder-api                       RUNNING    pid 2549, uptime 11:22:18
cinder-scheduler                 RUNNING    pid 2653, uptime 11:22:18
glance-api                       RUNNING    pid 2546, uptime 11:22:18
glance-registry                  RUNNING    pid 2608, uptime 11:22:18
heat-api                         RUNNING    pid 2638, uptime 11:22:18
heat-api-cfn                     RUNNING    pid 2592, uptime 11:22:18
heat-engine                      RUNNING    pid 2607, uptime 11:22:18
keystone                         RUNNING    pid 23684, uptime 10:06:32
nova-api                         RUNNING    pid 2538, uptime 11:22:18
nova-conductor                   RUNNING    pid 2543, uptime 11:22:18
nova-console                     RUNNING    pid 2568, uptime 11:22:18
nova-consoleauth                 RUNNING    pid 2553, uptime 11:22:18
nova-novncproxy                  RUNNING    pid 2537, uptime 11:22:18
nova-scheduler                   RUNNING    pid 2602, uptime 11:22:18
supervisor> quit
root@nodeg1:/var/log/contrail# date
Thu Aug 25 23:06:28 IST 2016
root@nodeg1:/var/log/contrail#

Revision history for this message

OpenContrail Admin (ci-admin-f) wrote on 2016-08-26: [Review update] R3.1

Review in progress for https://review.opencontrail.org/23606
Submitter: Megh Bhatt (<email address hidden>)

Revision history for this message

OpenContrail Admin (ci-admin-f) wrote on 2016-08-26: A change has been merged

Reviewed: https://review.opencontrail.org/23606
Committed: http://github.org/Juniper/contrail-controller/commit/681872321c672a4d581211bbda418e1b0d474983
Submitter: Zuul
Branch: R3.1

commit 681872321c672a4d581211bbda418e1b0d474983
Author: Megh Bhatt <email address hidden>
Date: Thu Aug 25 18:25:12 2016 -0700

Check for presence of 'X-USER-TOKEN' in self._headers before deleting

self._headers can be set to empty if self._authenticate raises an
Exception and hence we need to check if key 'X-USER-TOKEN' is
present before trying to delete it

Change-Id: I31bba531667f424de30c0c03302301c0c171a60d
Partial-Bug: #1616797

Megh Bhatt (meghb) on 2016-08-26

Changed in juniperopenstack:
milestone:	none → r3.2.0.0-fcs
assignee:	nobody → Megh Bhatt (meghb)
importance:	Undecided → Medium
importance:	Medium → High

Revision history for this message

Megh Bhatt (meghb) wrote on 2016-08-26:

Hi Pavana,
Can you please re-try the upgrade with an image containing the fix? I have checked in a fix to prevent the KeyError but we still need to debug the keystone intermittent failure issue.

Thanks

Megh

Revision history for this message

OpenContrail Admin (ci-admin-f) wrote on 2016-08-26: [Review update] master

Review in progress for https://review.opencontrail.org/23639
Submitter: Megh Bhatt (<email address hidden>)

Revision history for this message

OpenContrail Admin (ci-admin-f) wrote on 2016-08-26: [Review update] R3.0

Review in progress for https://review.opencontrail.org/23641
Submitter: Megh Bhatt (<email address hidden>)

Revision history for this message

OpenContrail Admin (ci-admin-f) wrote on 2016-08-27: A change has been merged

Reviewed: https://review.opencontrail.org/23639
Committed: http://github.org/Juniper/contrail-controller/commit/9a0c7e056750c2bcb61f9680393c30ef5acc2d58
Submitter: Zuul
Branch: master

commit 9a0c7e056750c2bcb61f9680393c30ef5acc2d58
Author: Megh Bhatt <email address hidden>
Date: Thu Aug 25 18:25:12 2016 -0700

Check for presence of 'X-USER-TOKEN' in self._headers before deleting

self._headers can be set to empty if self._authenticate raises an
Exception and hence we need to check if key 'X-USER-TOKEN' is
present before trying to delete it

Change-Id: I31bba531667f424de30c0c03302301c0c171a60d
Partial-Bug: #1616797
(cherry picked from commit 681872321c672a4d581211bbda418e1b0d474983)

Revision history for this message

OpenContrail Admin (ci-admin-f) wrote on 2016-08-27:

#10

Reviewed: https://review.opencontrail.org/23641
Committed: http://github.org/Juniper/contrail-controller/commit/0b01d6324f0d14ea3f3b06e99a0e9d1fdf3aa75b
Submitter: Zuul
Branch: R3.0

commit 0b01d6324f0d14ea3f3b06e99a0e9d1fdf3aa75b
Author: Megh Bhatt <email address hidden>
Date: Thu Aug 25 18:25:12 2016 -0700

Check for presence of 'X-USER-TOKEN' in self._headers before deleting

self._headers can be set to empty if self._authenticate raises an
Exception and hence we need to check if key 'X-USER-TOKEN' is
present before trying to delete it

Change-Id: I31bba531667f424de30c0c03302301c0c171a60d
Partial-Bug: #1616797
(cherry picked from commit 681872321c672a4d581211bbda418e1b0d474983)

Fawad (fshaikh) on 2016-12-21

tags:

added: wpc