OpenStack Compute (nova)

FAIL: tempest.thirdparty.boto.test_ec2_instance_run.InstanceRunTest.test_run_stop_terminate_instance -- Malformed request body: Cannot understand JSON

Bug #1223161 reported by Peter Portante on 2013-09-10

This bug report is a duplicate of: Bug #1229475: terminate_instance(): RuntimeError: Second simultaneous read on fileno 16 detected. Edit Remove

This bug affects 8 people

	Status	Importance	Assigned to
OpenStack Compute (nova)	Confirmed	Undecided	Unassigned
neutron	New	Undecided	Unassigned
tempest	Confirmed	Undecided	Unassigned

Bug Description

See http://logs.openstack.org/98/44098/11/check/gate-tempest-devstack-vm-neutron/68c9a41/console.html

2013-09-10 03:26:06.136 | ======================================================================
2013-09-10 03:26:06.136 | FAIL: tempest.thirdparty.boto.test_ec2_instance_run.InstanceRunTest.test_run_stop_terminate_instance[gate,smoke]
2013-09-10 03:26:06.137 | tempest.thirdparty.boto.test_ec2_instance_run.InstanceRunTest.test_run_stop_terminate_instance[gate,smoke]
2013-09-10 03:26:06.137 | ----------------------------------------------------------------------
2013-09-10 03:26:06.137 | _StringException: Empty attachments:
2013-09-10 03:26:06.137 | stderr
2013-09-10 03:26:06.138 | stdout
2013-09-10 03:26:06.138 |
2013-09-10 03:26:06.138 | pythonlogging:'': {{{
2013-09-10 03:26:06.139 | 2013-09-10 03:18:40,673 state: pending
2013-09-10 03:26:06.139 | 2013-09-10 03:18:47,211 State transition "pending" ==> "error" 6 second
2013-09-10 03:26:06.139 | }}}
2013-09-10 03:26:06.140 |
2013-09-10 03:26:06.140 | Traceback (most recent call last):
2013-09-10 03:26:06.140 | File "tempest/thirdparty/boto/test_ec2_instance_run.py", line 150, in test_run_stop_terminate_instance
2013-09-10 03:26:06.140 | self.assertInstanceStateWait(instance, "running")
2013-09-10 03:26:06.141 | File "tempest/thirdparty/boto/test.py", line 356, in assertInstanceStateWait
2013-09-10 03:26:06.141 | state = self.waitInstanceState(lfunction, wait_for)
2013-09-10 03:26:06.141 | File "tempest/thirdparty/boto/test.py", line 341, in waitInstanceState
2013-09-10 03:26:06.142 | self.valid_instance_state)
2013-09-10 03:26:06.142 | File "tempest/thirdparty/boto/test.py", line 332, in state_wait_gone
2013-09-10 03:26:06.142 | self.assertIn(state, valid_set | self.gone_set)
2013-09-10 03:26:06.142 | File "/usr/local/lib/python2.7/dist-packages/testtools/testcase.py", line 328, in assertIn
2013-09-10 03:26:06.143 | self.assertThat(haystack, Contains(needle))
2013-09-10 03:26:06.143 | File "/usr/local/lib/python2.7/dist-packages/testtools/testcase.py", line 417, in assertThat
2013-09-10 03:26:06.143 | raise MismatchError(matchee, matcher, mismatch, verbose)
2013-09-10 03:26:06.144 | MismatchError: u'error' not in set(['paused', 'terminated', 'running', 'stopped', 'pending', '_GONE', 'stopping', 'shutting-down'])

Tags:

Revision history for this message

Alex Gaynor (alex-gaynor) wrote on 2013-09-16: Re: test_run_stop_terminate_instance fails for check jobs

This isn't swift specific, I observed this fail under a tempest job for a horizon change

summary:

- test_run_stop_terminate_instance fails for swift check jobs
+ test_run_stop_terminate_instance fails for check jobs

Joe Gordon (jogo) on 2013-09-24

summary:

- test_run_stop_terminate_instance fails for check jobs
+ FAIL:
+ tempest.thirdparty.boto.test_ec2_instance_run.InstanceRunTest.test_run_stop_terminate_instance

Revision history for this message

Joe Gordon (jogo) wrote on 2013-09-24: Re: FAIL: tempest.thirdparty.boto.test_ec2_instance_run.InstanceRunTest.test_run_stop_terminate_instance

Looking at the logs it looks the issue is this stacktrace: http://logs.openstack.org/59/47659/6/check/gate-tempest-devstack-vm-neutron/fc83d44/logs/screen-n-cpu.txt.gz#_2013-09-23_18_25_17_379

Revision history for this message

Joe Gordon (jogo) wrote on 2013-09-24:

logstash query: @message:Cannot understand JSON* AND @fields.build_name:"gate-tempest-devstack-vm-neutron" AND @fields.build_status:"FAILURE" AND @fields.filename:"logs/screen-n-sch.txt"

Changed in nova:
status:	New → Confirmed

Joe Gordon (jogo) on 2013-09-24

tags:

added: ec2

Revision history for this message

Attila Fazekas (afazekas) wrote on 2013-09-25:

Does it happens in a not neutron job ?

Is the q-svc log always contains ERRORS ?

Revision history for this message

OpenStack Infra (hudson-openstack) wrote on 2013-09-26: Related fix proposed to tempest (master)

Related fix proposed to branch: master
Review: https://review.openstack.org/48412

Revision history for this message

Salvatore Orlando (salvatore-orlando) wrote on 2013-09-26: Re: FAIL: tempest.thirdparty.boto.test_ec2_instance_run.InstanceRunTest.test_run_stop_terminate_instance

I've noticed this in the nova logs - the instance if spawned and then aborted because a claim in nova compute fails: http://paste.openstack.org/show/47535/

Revision history for this message

Joe Gordon (jogo) wrote on 2013-09-26:

Salvatore, I think that logic is backwards. the claim is aborted because the instance is being deleted during spawn. A claim doesn't go into full effect until the instance is up and running (IIRC)

Joe Gordon (jogo) on 2013-09-26

tags:

added: havana-rc-potential

Xiang Hui (xianghui) on 2013-09-27

Changed in tempest:
status:	New → Confirmed

Revision history for this message

Hans Lindgren (hanlind) wrote on 2013-09-30:

In all logs referenced here, there is also instances of "RuntimeError: Second simultaneous read on fileno XX detected" indicating this is the same as bug 1229475.

Revision history for this message

Zhikun Liu (zhikunliu) wrote on 2013-09-30: AUTO: Zhi Kun ZK Liu is on vacation

I am out of the office until 10/07/2013.

I will take vacation from 28th Sep to 7th Oct . If have any urgent, please
call 13910806810

Note: This is an automated response to your message "[Bug 1223161] Re:
FAIL:
tempest.thirdparty.boto.test_ec2_instance_run.InstanceRunTest.test_run_stop_terminate_instance"
sent on 09/30/2013 16:06:38.

This is the only notification you will receive while this person is away.

Revision history for this message

Joe Gordon (jogo) wrote on 2013-09-30:

#10

It looks like this bug is still valid but infrequent, only 3 hits on logstash in the past 48 hours.

summary:

FAIL:
tempest.thirdparty.boto.test_ec2_instance_run.InstanceRunTest.test_run_stop_terminate_instance
+ -- Malformed request body: Cannot understand JSON

Revision history for this message

Davanum Srinivas (DIMS) (dims-v) wrote on 2013-10-01:

#11

Possible fix in https://review.openstack.org/#/c/49210/

Revision history for this message

Russell Bryant (russellb) wrote on 2013-10-02:

#12

Yes, I think this is a side effect of bug 1229475. While investigating that bug, I saw these types of failures, where neutronclient was getting data from rabbitmq, due to it using a bogus fd that was in use by the rpc code at the time.

Revision history for this message

Gary Kotton (garyk) wrote on 2013-10-04: assertEquals

#13

Hi,
About a month ago you –2'ed the following due to to the version release:
https://review.openstack.org/#/c/44237/
https://review.openstack.org/#/c/44238/
https://review.openstack.org/#/c/44239/
https://review.openstack.org/#/c/44243/
Can you please remove the blocking as the version is now open. I have already rebased.
Thanks
Gary