OpenStack Heat

Bug #1324102
Comment #8

Comment 8 for bug 1324102

Revision history for this message

William C. Arnold (barnold-8) wrote on 2014-06-17:

Re comment #6, I added some more tracing, and found that the major performance culprit in this test is constraint validation of the image and the key. Roughly constant-time hits include checking against quotas and template store. The image is being validated twice.
2014-06-17 15:13:26.167 8381 INFO heat.engine.service [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter create_stack
  2014-06-17 15:13:26.178 8381 INFO heat.engine.service [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter _validate_new_stack
  2014-06-17 15:13:26.433 8381 INFO heat.engine.service [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit _validate_new_stack
2014-06-17 15:13:26.435 8381 INFO heat.engine.parameters [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
2014-06-17 15:13:26.435 8381 INFO heat.engine.parameters [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
2014-06-17 15:13:26.436 8381 INFO heat.engine.parameters [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
2014-06-17 15:13:26.436 8381 INFO heat.engine.parameters [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
2014-06-17 15:13:26.436 8381 INFO heat.engine.parameters [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
2014-06-17 15:13:26.437 8381 INFO heat.engine.parameters [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
2014-06-17 15:13:26.438 8381 INFO heat.engine.service [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter _validate_deferred_auth_context
2014-06-17 15:13:26.438 8381 INFO heat.engine.service [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit _validate_deferred_auth_context
2014-06-17 15:13:26.438 8381 INFO heat.engine.parser [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
2014-06-17 15:13:26.439 8381 INFO heat.engine.template [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
2014-06-17 15:13:26.439 8381 INFO heat.engine.template [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
2014-06-17 15:13:26.440 8381 INFO heat.engine.parameter_groups [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
2014-06-17 15:13:26.441 8381 INFO heat.engine.parameter_groups [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
2014-06-17 15:13:26.445 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
2014-06-17 15:13:26.446 8381 INFO heat.engine.resource [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
2014-06-17 15:13:26.447 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
[note these are image and key]
  2014-06-17 15:13:26.447 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate_data
  2014-06-17 15:13:26.824 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate_data
  2014-06-17 15:13:26.825 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate_data
  2014-06-17 15:13:27.254 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate_data
2014-06-17 15:13:27.255 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate_data
2014-06-17 15:13:27.256 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate_data
2014-06-17 15:13:27.257 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate_data
2014-06-17 15:13:27.258 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate_data
2014-06-17 15:13:27.259 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
2014-06-17 15:13:27.259 8381 INFO heat.engine.resource [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
2014-06-17 15:13:27.260 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] before get self.BLOCK_DEVICE_MAPPING
2014-06-17 15:13:27.260 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] after get self.BLOCK_DEVICE_MAPPING
2014-06-17 15:13:27.260 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] before get self.IMAGE
  2014-06-17 15:13:27.261 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate_data
  2014-06-17 15:13:27.493 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate_data
2014-06-17 15:13:27.494 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] after get self.IMAGE
2014-06-17 15:13:27.494 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] before get self.NETWORKS
2014-06-17 15:13:27.495 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] after get self.NETWORKS
2014-06-17 15:13:27.495 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] before get self.METADATA
2014-06-17 15:13:27.496 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] after get self.METADATA
2014-06-17 15:13:27.496 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] before get self.PERSONALITY
2014-06-17 15:13:27.496 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] after get self.PERSONALITY
  2014-06-17 15:13:27.497 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] before nova_utils.absolute_limits
  2014-06-17 15:13:27.853 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] after nova_utils.absolute_limits
2014-06-17 15:13:27.853 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] before get self.SECURITY_GROUPS
2014-06-17 15:13:27.854 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] after get self.SECURITY_GROUPS
2014-06-17 15:13:27.855 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
2014-06-17 15:13:27.856 8381 INFO heat.engine.parser [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
  2014-06-17 15:13:27.856 8381 INFO heat.engine.parser [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter store
  2014-06-17 15:13:28.293 8381 INFO heat.engine.parser [-] exit store
2014-06-17 15:13:28.323 8381 INFO heat.engine.service [-] exit create_stack

Re comment #6, I added some more tracing, and found that the major performance culprit in this test is constraint validation  of the image and the key. Roughly constant-time hits include checking against quotas and template store. The image is being validated twice. 
2014-06-17 15:13:26.167 8381 INFO heat.engine.service [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter create_stack
  2014-06-17 15:13:26.178 8381 INFO heat.engine.service [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter _validate_new_stack
  2014-06-17 15:13:26.433 8381 INFO heat.engine.service [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit _validate_new_stack
2014-06-17 15:13:26.435 8381 INFO heat.engine.parameters [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
2014-06-17 15:13:26.435 8381 INFO heat.engine.parameters [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
2014-06-17 15:13:26.436 8381 INFO heat.engine.parameters [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
2014-06-17 15:13:26.436 8381 INFO heat.engine.parameters [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
2014-06-17 15:13:26.436 8381 INFO heat.engine.parameters [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
2014-06-17 15:13:26.437 8381 INFO heat.engine.parameters [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
2014-06-17 15:13:26.438 8381 INFO heat.engine.service [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter _validate_deferred_auth_context
2014-06-17 15:13:26.438 8381 INFO heat.engine.service [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit _validate_deferred_auth_context
2014-06-17 15:13:26.438 8381 INFO heat.engine.parser [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
2014-06-17 15:13:26.439 8381 INFO heat.engine.template [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
2014-06-17 15:13:26.439 8381 INFO heat.engine.template [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
2014-06-17 15:13:26.440 8381 INFO heat.engine.parameter_groups [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
2014-06-17 15:13:26.441 8381 INFO heat.engine.parameter_groups [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
2014-06-17 15:13:26.445 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
2014-06-17 15:13:26.446 8381 INFO heat.engine.resource [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
2014-06-17 15:13:26.447 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate
[note these are image and key]
  2014-06-17 15:13:26.447 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate_data
  2014-06-17 15:13:26.824 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate_data
  2014-06-17 15:13:26.825 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate_data
  2014-06-17 15:13:27.254 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate_data
2014-06-17 15:13:27.255 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate_data
2014-06-17 15:13:27.256 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate_data
2014-06-17 15:13:27.257 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate_data
2014-06-17 15:13:27.258 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate_data
2014-06-17 15:13:27.259 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
2014-06-17 15:13:27.259 8381 INFO heat.engine.resource [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
2014-06-17 15:13:27.260 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] before get self.BLOCK_DEVICE_MAPPING
2014-06-17 15:13:27.260 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] after get self.BLOCK_DEVICE_MAPPING
2014-06-17 15:13:27.260 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] before get self.IMAGE
  2014-06-17 15:13:27.261 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter validate_data
  2014-06-17 15:13:27.493 8381 INFO heat.engine.properties [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate_data
2014-06-17 15:13:27.494 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] after get self.IMAGE
2014-06-17 15:13:27.494 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] before get self.NETWORKS
2014-06-17 15:13:27.495 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] after get self.NETWORKS
2014-06-17 15:13:27.495 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] before get self.METADATA
2014-06-17 15:13:27.496 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] after get self.METADATA
2014-06-17 15:13:27.496 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] before get self.PERSONALITY
2014-06-17 15:13:27.496 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] after get self.PERSONALITY
  2014-06-17 15:13:27.497 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] before nova_utils.absolute_limits
  2014-06-17 15:13:27.853 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] after nova_utils.absolute_limits
2014-06-17 15:13:27.853 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] before get self.SECURITY_GROUPS
2014-06-17 15:13:27.854 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] after get self.SECURITY_GROUPS
2014-06-17 15:13:27.855 8381 INFO heat.engine.resources.server [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
2014-06-17 15:13:27.856 8381 INFO heat.engine.parser [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] exit validate
  2014-06-17 15:13:27.856 8381 INFO heat.engine.parser [req-a06a43f7-ad72-4e21-b513-ea5f54d79e2a None] enter store
  2014-06-17 15:13:28.293 8381 INFO heat.engine.parser [-] exit store
2014-06-17 15:13:28.323 8381 INFO heat.engine.service [-] exit create_stack