test_rebuild_server* tests timeout intermittently

[Thomas Herve]

As seen here: http://logs.openstack.org/72/62672/1/check/check-tempest-dsvm-postgres-full/cfd8223/console.html

There are 2 tracebacks, maybe related to bug #1079687 but I'm not sure

2013-12-17 15:43:39.810 | traceback-1: {{{
2013-12-17 15:43:39.811 | Traceback (most recent call last):
2013-12-17 15:43:39.811 | File "tempest/services/compute/json/servers_client.py", line 240, in rebuild
2013-12-17 15:43:39.811 | return self.action(server_id, 'rebuild', 'server', **kwargs)
2013-12-17 15:43:39.811 | File "tempest/services/compute/json/servers_client.py", line 198, in action
2013-12-17 15:43:39.811 | post_body, self.headers)
2013-12-17 15:43:39.811 | File "tempest/common/rest_client.py", line 302, in post
2013-12-17 15:43:39.812 | return self.request('POST', url, headers, body)
2013-12-17 15:43:39.812 | File "tempest/common/rest_client.py", line 436, in request
2013-12-17 15:43:39.812 | resp, resp_body)
2013-12-17 15:43:39.812 | File "tempest/common/rest_client.py", line 491, in _error_checker
2013-12-17 15:43:39.812 | raise exceptions.Conflict(resp_body)
2013-12-17 15:43:39.812 | Conflict: An object with that identifier already exists
2013-12-17 15:43:39.813 | Details: {u'conflictingRequest': {u'message': u"Cannot 'rebuild' while instance is in task_state rebuilding", u'code': 409}}
2013-12-17 15:43:39.813 | }}}
2013-12-17 15:43:39.813 |
2013-12-17 15:43:39.813 | traceback-2: {{{
2013-12-17 15:43:39.813 | Traceback (most recent call last):
2013-12-17 15:43:39.813 | File "tempest/services/compute/json/servers_client.py", line 162, in wait_for_server_status
2013-12-17 15:43:39.814 | raise_on_error=raise_on_error)
2013-12-17 15:43:39.814 | File "tempest/common/waiters.py", line 73, in wait_for_server_status
2013-12-17 15:43:39.814 | raise exceptions.BuildErrorException(server_id=server_id)
2013-12-17 15:43:39.814 | BuildErrorException: Server 6c48e431-a0b9-4a99-99d5-f9db152b8bba failed to build and is in ERROR status
2013-12-17 15:43:39.814 | }}}

[Sean Dague (sdague)]

not a tempest bug. And just a stack trace.

[Steve Baker (steve-stevebaker)]

This traceback comes from a nova test, and does not involve heat.

[Matt Riedemann (mriedem)]

This isn't showing up in the gate in the last 7 days:

http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOlwiRkFJTDogdGVtcGVzdC5hcGkuY29tcHV0ZS5hZG1pbi50ZXN0X3NlcnZlcnMuU2VydmVyc0FkbWluVGVzdEpTT04udGVzdF9yZWJ1aWxkX3NlcnZlcl9pbl9lcnJvcl9zdGF0ZVwiIEFORCBmaWxlbmFtZTpcImNvbnNvbGUuaHRtbFwiIEFORCBidWlsZF9xdWV1ZTpcImdhdGVcIiIsImZpZWxkcyI6W10sIm9mZnNldCI6MCwidGltZWZyYW1lIjoiNjA0ODAwIiwiZ3JhcGhtb2RlIjoiY291bnQiLCJ0aW1lIjp7InVzZXJfaW50ZXJ2YWwiOjB9LCJzdGFtcCI6MTM5MDc3NDA5NzI5OX0=

[Matt Riedemann (mriedem)]

Nevermind, expanding to 2 weeks shows a hit:

http://logs.openstack.org/73/65973/2/gate/gate-tempest-dsvm-full/6933457/console.html.gz

This is probably a better fingerprint:

http://logstash.openstack.org/#eyJzZWFyY2giOiJtZXNzYWdlOlwiQ2Fubm90ICdyZWJ1aWxkJyB3aGlsZSBpbnN0YW5jZSBpcyBpbiB0YXNrX3N0YXRlIHJlYnVpbGRpbmdcIiBBTkQgZmlsZW5hbWU6XCJjb25zb2xlLmh0bWxcIiIsImZpZWxkcyI6W10sIm9mZnNldCI6MCwidGltZWZyYW1lIjoiNjA0ODAwIiwiZ3JhcGhtb2RlIjoiY291bnQiLCJ0aW1lIjp7InVzZXJfaW50ZXJ2YWwiOjB9LCJzdGFtcCI6MTM5MDc3ODk2NzE4M30=

6 hits in 7 days.

[Matt Riedemann (mriedem)]

Looks like test_rebuild_server can also fail with this:

http://logs.openstack.org/76/67976/2/check/check-grenade-dsvm/512d1bc/console.html.gz#_2014-01-21_04_51_58_457

[Matt Riedemann (mriedem)]

The difference seems to be that with test_rebuild_server, the failure is "Current status: REBUILD. Current task state: rebuilding." and with the rebuild from error it's "Current status: ERROR. Current task state: rebuilding.". Either way they are just timing out in the rebuild, so the root cause is probably the same.

[Matt Riedemann (mriedem)]

e-r query patch: https://review.openstack.org/#/c/69242/

[Matt Riedemann (mriedem)]

Hmm, also hits "test_rebuild_server_in_stop_state".

[Dolph Mathews (dolph)]

Similar variant:

Traceback (most recent call last):
  File "tempest/services/compute/json/servers_client.py", line 245, in rebuild
    return self.action(server_id, 'rebuild', 'server', **kwargs)
  File "tempest/services/compute/json/servers_client.py", line 203, in action
    post_body)
  File "tempest/common/rest_client.py", line 201, in post
    return self.request('POST', url, headers, body)
  File "tempest/common/rest_client.py", line 443, in request
    resp, resp_body)
  File "tempest/common/rest_client.py", line 497, in _error_checker
    raise exceptions.Conflict(resp_body)
Conflict: An object with that identifier already exists
Details: {u'message': u"Cannot 'rebuild' while instance is in task_state powering-off", u'code': 409}

[Sean Dague (sdague)]

This is a gate affecting bug

[Joe Gordon (jogo)]

no hits anymore, looks like this was fixed