Magnum unstable/fails with devstack (was pod-create fails ('NoneType' object has no attribute 'status'))

[Martin Falatic]

This worked in recent weeks but is not working now, possibly due to changes on master within the last week or so.

Using a new devstack install and following the dev quickstart, things work fine until you run pod-create (using k8s 0.15 example):

magnum pod-create --manifest ./redis-master.yaml --bay k8sbay

ERROR: 'NoneType' object has no attribute 'status' (HTTP 500)

---- Note: A similar error occurs with k8s 1.0.1 version of the example, FWIW (tried this later, may cause other side-effects):
---- ERROR: Timed out waiting for a reply to message ID <id> (HTTP 500)

Error details:

m-api:

2015-08-05 11:24:38.999 ERROR wsme.api [req-039a9274-da16-417e-9aa1-bd0c78d230f1 admin admin] Server-side error: "'NoneType' object has no attribute 'status'
Traceback (most recent call last):

  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply
    executor_callback))

  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch
    executor_callback)

  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 129, in _do_dispatch
    result = func(ctxt, **new_args)

  File "/opt/stack/magnum/magnum/conductor/handlers/k8s_conductor.py", line 100, in pod_create
    pod.status = resp.status.phase

AttributeError: 'NoneType' object has no attribute 'status'
". Detail:

Traceback (most recent call last):

  File "/usr/local/lib/python2.7/dist-packages/wsmeext/pecan.py", line 84, in callfunction
    result = f(self, *args, **kwargs)

  File "<string>", line 2, in post

  File "/opt/stack/magnum/magnum/api/validation.py", line 38, in handler
    return func(*args, **kwargs)

  File "/opt/stack/magnum/magnum/api/controllers/v1/pod.py", line 264, in post
    new_pod = pecan.request.rpcapi.pod_create(pod_obj)

  File "/opt/stack/magnum/magnum/conductor/api.py", line 86, in pod_create
    return self._call('pod_create', pod=pod)

  File "/opt/stack/magnum/magnum/common/rpc_service.py", line 103, in _call
    return self._client.call(self._context, method, *args, **kwargs)

  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 403, in call
    return self.prepare().call(ctxt, method, **kwargs)

  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/client.py", line 158, in call
    retry=self.retry)

  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/transport.py", line 90, in _send
    timeout=timeout, retry=retry)

  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 431, in send
    retry=retry)

  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/_drivers/amqpdriver.py", line 422, in _send
    raise result

AttributeError: 'NoneType' object has no attribute 'status'
Traceback (most recent call last):

  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply
    executor_callback))

  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch
    executor_callback)

  File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 129, in _do_dispatch
    result = func(ctxt, **new_args)

  File "/opt/stack/magnum/magnum/conductor/handlers/k8s_conductor.py", line 100, in pod_create
    pod.status = resp.status.phase

AttributeError: 'NoneType' object has no attribute 'status'

m-cond:

2015-08-05 11:24:38.961 DEBUG magnum.conductor.handlers.k8s_conductor [req-039a9274-da16-417e-9aa1-bd0c78d230f1 admin admin] pod_create from (pid=1557) pod_crea
te /opt/stack/magnum/magnum/conductor/handlers/k8s_conductor.py:89
2015-08-05 11:24:38.979 ERROR oslo_messaging.rpc.dispatcher [req-039a9274-da16-417e-9aa1-bd0c78d230f1 admin admin] Exception during message handling: 'NoneType'
 object has no attribute 'status'
2015-08-05 11:24:38.979 TRACE oslo_messaging.rpc.dispatcher Traceback (most recent call last):
2015-08-05 11:24:38.979 TRACE oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _disp
atch_and_reply
2015-08-05 11:24:38.979 TRACE oslo_messaging.rpc.dispatcher executor_callback))
2015-08-05 11:24:38.979 TRACE oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _disp
atch
2015-08-05 11:24:38.979 TRACE oslo_messaging.rpc.dispatcher executor_callback)
2015-08-05 11:24:38.979 TRACE oslo_messaging.rpc.dispatcher File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 129, in _do_dispatch
2015-08-05 11:24:38.979 TRACE oslo_messaging.rpc.dispatcher result = func(ctxt, **new_args)
2015-08-05 11:24:38.979 TRACE oslo_messaging.rpc.dispatcher File "/opt/stack/magnum/magnum/conductor/handlers/k8s_conductor.py", line 100, in pod_create
2015-08-05 11:24:38.979 TRACE oslo_messaging.rpc.dispatcher pod.status = resp.status.phase
2015-08-05 11:24:38.979 TRACE oslo_messaging.rpc.dispatcher AttributeError: 'NoneType' object has no attribute 'status'
2015-08-05 11:24:38.979 TRACE oslo_messaging.rpc.dispatcher
2015-08-05 11:24:38.980 ERROR oslo_messaging._drivers.common [req-039a9274-da16-417e-9aa1-bd0c78d230f1 admin admin] Returning exception 'NoneType' object has no attribute 'status' to caller
2015-08-05 11:24:38.981 ERROR oslo_messaging._drivers.common [req-039a9274-da16-417e-9aa1-bd0c78d230f1 admin admin] ['Traceback (most recent call last):\n', ' File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 142, in _dispatch_and_reply\n executor_callback))\n', ' File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 186, in _dispatch\n executor_callback)\n', ' File "/usr/local/lib/python2.7/dist-packages/oslo_messaging/rpc/dispatcher.py", line 129, in _do_dispatch\n result = func(ctxt, **new_args)\n', ' File "/opt/stack/magnum/magnum/conductor/handlers/k8s_conductor.py", line 100, in pod_create\n pod.status = resp.status.phase\n', "AttributeError: 'NoneType' object has no attribute 'status'\n"]

[Martin Falatic (martinfalatic)]

More info:

In magnum/conductor/handlers/k8s_conductor.py:93 (the pod_create function):

    resp = self.k8s_api.createPod(body=manifest, namespaces='default')

the value of resp == None

[Martin Falatic (martinfalatic)]

This is the manifest being passed as the body arg to createPod():

2015-08-05 14:52:13.853 DEBUG magnum.conductor.handlers.k8s_conductor [req-609c71b2-88a1-4dc9-9b8f-b1e4320ab256 admin admin] pod_create manifest is {'kind': 'Pod', 'spec': {'containers': [{'name': 'master', 'env': [{'name': 'MASTER', 'value': 'true'}], 'image': 'kubernetes/redis:v1', 'volumeMounts': [{'mountPath': '/redis-master-data', 'name': 'data'}], 'ports': [{'containerPort': 6379}], 'resources': {'limits': {'cpu': '1'}}}, {'image': 'kubernetes/redis:v1', 'name': 'sentinel', 'env': [{'name': 'SENTINEL', 'value': 'true'}], 'ports': [{'containerPort': 26379}]}], 'volumes': [{'emptyDir': {}, 'name': 'data'}]}, 'apiVersion': 'v1beta3', 'metadata': {'labels': {'redis-sentinel': 'true', 'role': 'master', 'name': 'redis'}, 'name': 'redis-master'}} from (pid=14576) pod_create /opt/stack/magnum/magnum/conductor/handlers/k8s_conductor.py:92

[Ton Ngo (ton-i)]

The functional test for creating pod is failing in similar way:
tox -e functional magnum.tests.functional.test_magnum_python_client.TestKubernetesAPIs.test_pod_apis
.....
======================================================================
FAIL: magnum.tests.functional.test_magnum_python_client.TestKubernetesAPIs.test_pod_apis
tags: worker-0
----------------------------------------------------------------------
Empty attachments:
  stderr
  stdout

Traceback (most recent call last):
  File "magnum/tests/functional/test_magnum_python_client.py", line 238, in test_pod_apis
    self.assertEqual(resp.metadata['name'], 'test')
AttributeError: 'NoneType' object has no attribute 'metadata'
Ran 1 tests in 244.258s
FAILED (id=21, failures=1)
error: testr failed (1)
ERROR: InvocationError: '/opt/stack/magnum/.tox/functional/bin/python setup.py testr --slowest --testr-args=magnum.tests.functional.test_magnum_python_client.TestKubernetesAPIs.test_pod_apis'
______________________________________________________________________ summary _______________________________________________________________________
ERROR: functional: commands failed

[Vilobh Meshram (vilobhmm)]

This call is failing https://github.com/openstack/magnum/blob/master/magnum/common/pythonk8sclient/client/ApivbetaApi.py#L2352

as a result of which resp object is None

Need to see why createPod is failing

[Martin Falatic (martinfalatic)]

More detail from the m-api log:

AttributeError: 'NoneType' object has no attribute 'status'

172.29.84.47 - - [05/Aug/2015 11:24:39] "POST /v1/pods HTTP/1.1" 500 130
2015-08-05 11:24:43.659 DEBUG keystoneclient.session [req-039a9274-da16-417e-9aa1-bd0c78d230f1 admin admin] REQ: curl
-g -i --cacert "/opt/stack/data/ca-bundle.pem" -X GET http://172.29.84.47:35357/v3/auth/tokens -H "X-Subject-Token: {SHA1}98b5092c82b646493ebeb78315df5586d487ea
33" -H "User-Agent: python-keystoneclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}87ef2d3b91f4d1347a9576bc1efd620a9576be2f" from (pid=
1482) _http_log_request /usr/local/lib/python2.7/dist-packages/keystoneclient/session.py:195
2015-08-05 11:24:43.761 DEBUG keystoneclient.session [req-039a9274-da16-417e-9aa1-bd0c78d230f1 admin admin] RESP: [200
] content-length: 7160 x-subject-token: {SHA1}98b5092c82b646493ebeb78315df5586d487ea33 vary: X-Auth-Token keep-alive: timeout=5, max=99 server: Apache/2.4.7 (Ub
untu) connection: Keep-Alive date: Wed, 05 Aug 2015 18:24:43 GMT content-type: application/json x-openstack-request-id: req-ef5eed47-d738-4df5-b137-ed6eaa76f7d6

RESP BODY: {"token": {"methods": ["password", "token"], "roles": [{"id": "efb230b10ff94f15bf934c0daecfc65f", "name": "admin"}], "expires_at": "2015-08-05T20:24:
43.000000Z", "project": {"domain": {"id": "default", "name": "Default"}, "id": "39a7a80f9f664e038b8b3abad78bc467", "name": "admin"}, "catalog": "<removed>", "ex
tras": {}, "user": {"domain": {"id": "default", "name": "Default"}, "id": "c48526d5e3d943d48e197793db5ad51c", "name": "admin"}, "audit_ids": ["eBiZRGJLQPi2p52av
7_NFg"], "issued_at": "2015-08-05T18:24:43.645567"}}
 from (pid=1482) _http_log_response /usr/local/lib/python2.7/dist-packages/keystoneclient/session.py:224
172.29.84.47 - - [05/Aug/2015 11:24:43] "GET /v1/bays/k8sbay HTTP/1.1" 200 665

[Martin Falatic (martinfalatic)]

{u'kind': u'Pod', u'spec': {u'volumes': [{u'emptyDir': {}, u'name': u'data'}], u'containers': [{u'name': u'master', u'image': u'kubernetes/redis:v1', u'volumeMounts': [{u'mountPath': u'/redis-master-data', u'name': u'data'}], u'env': [{u'name': u'MASTER', u'value': u'true'}], u'ports': [{u'containerPort': 6379}], u'resources': {u'limits': {u'cpu': u'1'}}}, {u'image': u'kubernetes/redis:v1', u'name': u'sentinel', u'env': [{u'name': u'SENTINEL', u'value': u'true'}], u'ports': [{u'containerPort': 26379}]}]}, u'apiVersion': u'v1beta3', u'metadata': {u'labels': {u'role': u'master', u'redis-sentinel': u'true', u'name': u'redis'}, u'name': u'redis-master'}}

[Vilobh Meshram (vilobhmm)]

Further debugging with kube-apiserver showed following message

"reflector.go:123] Failed to list *api.Namespace: Get http://0.0.0.0:8080/api/v1beta3/namespaces: dial tcp 0.0.0.0:8080: connection refused"

[Martin Falatic (martinfalatic)]

To be specific, I get the following repeatedly after running kube-apiserver with debugging on the master:

E0818 20:11:17.150939 2233 reflector.go:123] Failed to list *api.Namespace: Get http://0.0.0.0:8080/api/v1beta3/namespaces: dial tcp 0.0.0.0:8080: connection refused
E0818 20:11:18.149898 2233 reflector.go:123] Failed to list *api.LimitRange: Get http://0.0.0.0:8080/api/v1beta3/limitranges: dial tcp 0.0.0.0:8080: connection refused
E0818 20:11:18.150970 2233 reflector.go:123] Failed to list *api.ResourceQuota: Get http://0.0.0.0:8080/api/v1beta3/resourcequotas: dial tcp 0.0.0.0:8080: connection refused

[Martin Falatic (martinfalatic)]

Those errors are seen prior to any attempt to create a pod - also, the pod-create failure isn't adding new errors on the master either.

An attempt to directly create the pod on the master didn't work either:

kubectl create -f redis-master.yaml
Error: Post http://localhost:8080/api/v1beta3/namespaces/default/pods: dial tcp 127.0.0.1:8080: connection refused

[Vilobh Meshram (vilobhmm)]

Anyone can encounter this problem who tries to deploy magnum in devstack. There has been some changes recently as a result of which the createPoD k8s rest api fails returning 500.

[Daneyon Hansen (danehans)]

As a work around, I use the native tools instead of Magnum for creating a pod and service. I ssh to a minion and use the web.pod and web.service manifests located in /etc/kubernetes/examples for testing:

$ kubectl create -f /etc/kubernetes/examples/web.pod
$ kubectl create -f /etc/kubernetes/examples/web.service

Verify the pod and service is running:
$ kubectl show pods
$ kubectl show services

If the pod and service has been successfully instantiated, you should be able to curl the associated IP/port.

[Daneyon Hansen (danehans)]

This bug also appears to effect creating a k8s service using magnum. Note: I am able to create a pod and service using kubectl.

$ magnum --debug service-create --bay k8s --manifest /opt/stack/web.service
DEBUG (v2:76) Making authentication request to http://172.29.74.86:5000/v2.0/tokens
INFO (connectionpool:203) Starting new HTTP connection (1): 172.29.74.86
DEBUG (connectionpool:383) "POST /v2.0/tokens HTTP/1.1" 200 4333
DEBUG (iso8601:184) Parsed 2015-08-26T19:26:46Z into {'tz_sign': None, 'second_fraction': None, 'hour': u'19', 'daydash': u'26', 'tz_hour': None, 'month': None, 'timezone': u'Z', 'second': u'46', 'tz_minute': None, 'year': u'2015', 'separator': u'T', 'monthdash': u'08', 'day': None, 'minute': u'26'} with default timezone <iso8601.iso8601.Utc object at 0x7fd4812cc350>
DEBUG (iso8601:140) Got u'2015' for 'year' with default None
DEBUG (iso8601:140) Got u'08' for 'monthdash' with default 1
DEBUG (iso8601:140) Got 8 for 'month' with default 8
DEBUG (iso8601:140) Got u'26' for 'daydash' with default 1
DEBUG (iso8601:140) Got 26 for 'day' with default 26
DEBUG (iso8601:140) Got u'19' for 'hour' with default None
DEBUG (iso8601:140) Got u'26' for 'minute' with default None
DEBUG (iso8601:140) Got u'46' for 'second' with default None
DEBUG (httpclient:105) curl -i -X GET -H 'X-Auth-Token: c31e0d94bd0c49759933825ed0c0cdb9' -H 'Content-Type: application/json' -H 'Accept: application/json' -H 'User-Agent: python-magnumclient' http://172.29.74.86:9511/v1/bays/k8s
2015-08-26 17:26:46.330 DEBUG keystoneclient.session [req-87113948-7e7f-40e1-82cf-1f3a8432a6f5 admin admin] REQ: curl -g -i --cacert "/opt/stack/data/ca-bundle.pem" -X GET http://172.29.74.86:35357/v3/auth/tokens -H "X-Subject-Token: {SHA1}5c7e8642fa7adf9aa2bb3c928faeb9fa35a0576e" -H "User-Agent: python-keystoneclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}ea2994b829b37d68d9e57e0e29066ab86536e3a2" from (pid=44611) _http_log_request /usr/local/lib/python2.7/dist-packages/keystoneclient/session.py:195
2015-08-26 17:26:46.372 DEBUG keystoneclient.session [req-87113948-7e7f-40e1-82cf-1f3a8432a6f5 admin admin] RESP: [200] content-length: 7701 x-subject-token: {SHA1}5c7e8642fa7adf9aa2bb3c928faeb9fa35a0576e vary: X-Auth-Token keep-alive: timeout=5, max=100 server: Apache/2.4.7 (Ubuntu) connection: Keep-Alive date: Wed, 26 Aug 2015 17:26:46 GMT content-type: application/json x-openstack-request-id: req-b2112ac8-f90d-46bf-a795-ea268704ca6c
RESP BODY: {"token": {"methods": ["password", "token"], "roles": [{"id": "080ed7420fe14e6fad562d0f4311acc5", "name": "admin"}], "expires_at": "2015-08-26T19:26:46.000000Z", "project": {"domain": {"id": "default", "name": "Default"}, "id": "d1611f2be8554e4e941caac9b7733eca", "name": "admin"}, "catalog": "<removed>", "extras": {}, "user": {"domain": {"id": "default", "name": "Default"}, "id": "1d562b4a46ef4acf81f9727c8f238b38", "name": "admin"}, "audit_ids": ["8FzaiJGZQd2x85CQXxAEYw"], "issued_at": "2015-08-26T17:26:46.302036"}}
 from (pid=44611) _http_log_response /usr/local/lib/python2.7/dist-packages/keystoneclient/session.py:224
172.29.74.86 - - [26/Aug/2015 17:26:46] "GET /v1/bays/k8s HTTP/1.1" 200 686
DEBUG (httpclient:115)
HTTP...

[Daneyon Hansen (danehans)]

I provided the incorrect show commands in #11. It should be get pods/services and not show pods/services.

[Martin Falatic (martinfalatic)]

Closing as "Cannot reproduce (anymore)".

After tearing down all test machines on that VLAN and reinstalling OS+devstack on one only, I'm not seeing the problem anymore (at least not yet). In my config, it is possible for machines to cross-talk - if two machines are listening for the same IP address they will see the other machine's network advertising it as well (even if it's not assigned to that VLAN). Furthermore this seems to persist even after unstacking due to components and configurations by devstack. Finally, there were evidently other intermediate bugs that prevented VMs from being properly removed, further complicating the situation. A combination of changes since the problem was first seen (which wasn't a problem before that) as well as the fact that the internal network (or configuration of openstack's network currently) is more promiscuous than expected seems to be the root causes. One should exercise caution with shared network environments and Openstack Liberty's Magnum (and in case of problems, watch for resources that nova, etc., should have removed but did not, as these can interfere with current processes).