Tacker Error# HeatClientException: ERROR: Property error: : resources.vdu1.properties.image: : "Cirros" does not validate glance.image (constraint not found)

Asked by Abhijeet

After successful deployment of tacker/mitaka,
Now we are facing an error "HeatClientException: ERROR: Property error: : resources.vdu1.properties.image: : "Cirros" does not validate glance.image (constraint not found)" while launching any heat stack or deploying VNF after on-boarding.

I am able to spawn an instance directly through nova, but while trying it either with heat stack or VNF deployment above error is coming. Attaching tacker logs for the ref#.
Tacker.log
_______________________________________________________________________
2017-03-06 20:00:29.839 6417 INFO tacker.service [-] Tacker service started, listening on 10.139.4.100:9890
2017-03-06 20:00:29.839 6417 INFO tacker.openstack.common.service [-] Starting 0 workers
2017-03-06 20:00:29.840 6417 DEBUG tacker.openstack.common.service [-] Full set of CONF: wait /usr/local/lib/python2.7/dist-packages/tacker/openstack/common/service.py:387
2017-03-06 20:00:29.840 6417 DEBUG tacker.openstack.common.service [-] ******************************************************************************** log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2503
2017-03-06 20:00:29.840 6417 DEBUG tacker.openstack.common.service [-] Configuration options gathered from: log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2504
2017-03-06 20:00:29.840 6417 DEBUG tacker.openstack.common.service [-] command line args: ['--config-file', '/usr/local/etc/tacker/tacker.conf', '--log-file', '/var/log/tacker/tacker.log'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2505
2017-03-06 20:00:29.840 6417 DEBUG tacker.openstack.common.service [-] config files: ['/usr/local/etc/tacker/tacker.conf'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2507
2017-03-06 20:00:29.840 6417 DEBUG tacker.openstack.common.service [-] ================================================================================ log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2508
2017-03-06 20:00:29.841 6417 DEBUG tacker.openstack.common.service [-] allow_bulk = True log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.841 6417 DEBUG tacker.openstack.common.service [-] allow_pagination = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.841 6417 DEBUG tacker.openstack.common.service [-] allow_sorting = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.841 6417 DEBUG tacker.openstack.common.service [-] api_extensions_path = log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.841 6417 DEBUG tacker.openstack.common.service [-] api_paste_config = api-paste.ini log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.841 6417 DEBUG tacker.openstack.common.service [-] api_workers = 0 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.841 6417 DEBUG tacker.openstack.common.service [-] auth_strategy = keystone log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.842 6417 DEBUG tacker.openstack.common.service [-] backdoor_port = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.842 6417 DEBUG tacker.openstack.common.service [-] backlog = 4096 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.842 6417 DEBUG tacker.openstack.common.service [-] bind_host = 10.139.4.100 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.842 6417 DEBUG tacker.openstack.common.service [-] bind_port = 9890 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.842 6417 DEBUG tacker.openstack.common.service [-] config_dir = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.842 6417 DEBUG tacker.openstack.common.service [-] config_file = ['/usr/local/etc/tacker/tacker.conf'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.842 6417 DEBUG tacker.openstack.common.service [-] control_exchange = tacker log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.843 6417 DEBUG tacker.openstack.common.service [-] debug = True log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.843 6417 DEBUG tacker.openstack.common.service [-] default_log_levels = ['amqp=WARN', 'amqplib=WARN', 'boto=WARN', 'qpid=WARN', 'sqlalchemy=WARN', 'suds=INFO', 'iso8601=WARN'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.843 6417 DEBUG tacker.openstack.common.service [-] disable_process_locking = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.843 6417 DEBUG tacker.openstack.common.service [-] fatal_deprecations = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.843 6417 DEBUG tacker.openstack.common.service [-] host = controler log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.843 6417 DEBUG tacker.openstack.common.service [-] instance_format = [instance: %(uuid)s] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.843 6417 DEBUG tacker.openstack.common.service [-] instance_uuid_format = [instance: %(uuid)s] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.843 6417 DEBUG tacker.openstack.common.service [-] lock_path = /var/lib/tacker/lock log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.844 6417 DEBUG tacker.openstack.common.service [-] log_config_append = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.844 6417 DEBUG tacker.openstack.common.service [-] log_date_format = %Y-%m-%d %H:%M:%S log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.844 6417 DEBUG tacker.openstack.common.service [-] log_dir = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.844 6417 DEBUG tacker.openstack.common.service [-] log_file = /var/log/tacker/tacker.log log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.844 6417 DEBUG tacker.openstack.common.service [-] log_format = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.844 6417 DEBUG tacker.openstack.common.service [-] logging_context_format_string = %(asctime)s.%(msecs)03d %(process)d %(levelname)s %(name)s [%(request_id)s %(user_identity)s] %(instance)s%(message)s log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.844 6417 DEBUG tacker.openstack.common.service [-] logging_debug_format_suffix = %(funcName)s %(pathname)s:%(lineno)d log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.845 6417 DEBUG tacker.openstack.common.service [-] logging_default_format_string = %(asctime)s.%(msecs)03d %(process)d %(levelname)s %(name)s [-] %(instance)s%(message)s log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.845 6417 DEBUG tacker.openstack.common.service [-] logging_exception_prefix = %(asctime)s.%(msecs)03d %(process)d TRACE %(name)s %(instance)s log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.845 6417 DEBUG tacker.openstack.common.service [-] max_header_line = 16384 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.845 6417 DEBUG tacker.openstack.common.service [-] memcached_servers = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.845 6417 DEBUG tacker.openstack.common.service [-] nova_admin_auth_url = http://localhost:5000/v2.0 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.845 6417 DEBUG tacker.openstack.common.service [-] nova_admin_password = **** log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.845 6417 DEBUG tacker.openstack.common.service [-] nova_admin_tenant_id = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.846 6417 DEBUG tacker.openstack.common.service [-] nova_admin_username = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.846 6417 DEBUG tacker.openstack.common.service [-] nova_api_insecure = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.846 6417 DEBUG tacker.openstack.common.service [-] nova_ca_certificates_file = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.846 6417 DEBUG tacker.openstack.common.service [-] nova_region_name = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.846 6417 DEBUG tacker.openstack.common.service [-] nova_url = http://127.0.0.1:8774/v2 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.846 6417 DEBUG tacker.openstack.common.service [-] pagination_max_limit = -1 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.846 6417 DEBUG tacker.openstack.common.service [-] periodic_fuzzy_delay = 5 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.846 6417 DEBUG tacker.openstack.common.service [-] periodic_interval = 40 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.847 6417 DEBUG tacker.openstack.common.service [-] policy_file = /usr/local/etc/tacker/policy.json log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.847 6417 DEBUG tacker.openstack.common.service [-] publish_errors = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.847 6417 DEBUG tacker.openstack.common.service [-] retry_until_window = 30 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.847 6417 DEBUG tacker.openstack.common.service [-] rpc_backend = rabbit log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.847 6417 DEBUG tacker.openstack.common.service [-] run_external_periodic_tasks = True log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.847 6417 DEBUG tacker.openstack.common.service [-] service_plugins = ['vnfm', 'nfvo'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.847 6417 DEBUG tacker.openstack.common.service [-] ssl_ca_file = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.848 6417 DEBUG tacker.openstack.common.service [-] ssl_cert_file = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.848 6417 DEBUG tacker.openstack.common.service [-] ssl_key_file = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.848 6417 DEBUG tacker.openstack.common.service [-] state_path = /var/lib/tacker log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.848 6417 DEBUG tacker.openstack.common.service [-] syslog_log_facility = LOG_USER log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.848 6417 DEBUG tacker.openstack.common.service [-] tcp_keepidle = 600 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.848 6417 DEBUG tacker.openstack.common.service [-] transport_url = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.848 6417 DEBUG tacker.openstack.common.service [-] use_ssl = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.849 6417 DEBUG tacker.openstack.common.service [-] use_stderr = True log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.849 6417 DEBUG tacker.openstack.common.service [-] use_syslog = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.849 6417 DEBUG tacker.openstack.common.service [-] verbose = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 20:00:29.849 6417 DEBUG tacker.openstack.common.service [-] tacker_heat.flavor_extra_specs = {} log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.849 6417 DEBUG tacker.openstack.common.service [-] tacker_heat.stack_retries = 60 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.849 6417 DEBUG tacker.openstack.common.service [-] tacker_heat.stack_retry_wait = 5 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.850 6417 DEBUG tacker.openstack.common.service [-] nfvo_vim.default_vim = VIM0 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.850 6417 DEBUG tacker.openstack.common.service [-] nfvo_vim.vim_drivers = ['openstack'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.850 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.amqp_auto_delete = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.850 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.amqp_durable_queues = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.850 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.fake_rabbit = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.850 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.heartbeat_rate = 2 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.850 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.heartbeat_timeout_threshold = 60 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.851 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.kombu_compression = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.851 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.kombu_failover_strategy = round-robin log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.851 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.kombu_missing_consumer_retry_timeout = 60 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.851 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.kombu_reconnect_delay = 1.0 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.851 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.kombu_ssl_ca_certs = log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.851 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.kombu_ssl_certfile = log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.851 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.kombu_ssl_keyfile = log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.851 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.kombu_ssl_version = log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.852 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.rabbit_ha_queues = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.852 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.rabbit_host = localhost log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.852 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.rabbit_hosts = ['localhost:5672'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.852 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.rabbit_interval_max = 30 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.852 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.rabbit_login_method = AMQPLAIN log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.852 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.rabbit_max_retries = 0 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.852 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.rabbit_password = **** log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.853 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.rabbit_port = 5672 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.853 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.rabbit_qos_prefetch_count = 0 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.853 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.rabbit_retry_backoff = 2 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.853 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.rabbit_retry_interval = 1 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.853 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.rabbit_transient_queues_ttl = 1800 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.853 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.rabbit_use_ssl = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.853 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.rabbit_userid = guest log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.854 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.rabbit_virtual_host = / log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.854 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_rabbit.rpc_conn_pool_size = 30 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.854 6417 DEBUG tacker.openstack.common.service [-] monitor.check_intvl = 10 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.854 6417 DEBUG tacker.openstack.common.service [-] database.backend = sqlalchemy log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.854 6417 DEBUG tacker.openstack.common.service [-] database.connection = **** log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.854 6417 DEBUG tacker.openstack.common.service [-] database.connection_debug = 0 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.854 6417 DEBUG tacker.openstack.common.service [-] database.connection_trace = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.855 6417 DEBUG tacker.openstack.common.service [-] database.db_inc_retry_interval = True log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.855 6417 DEBUG tacker.openstack.common.service [-] database.db_max_retries = 20 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.855 6417 DEBUG tacker.openstack.common.service [-] database.db_max_retry_interval = 10 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.855 6417 DEBUG tacker.openstack.common.service [-] database.db_retry_interval = 1 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.855 6417 DEBUG tacker.openstack.common.service [-] database.idle_timeout = 3600 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.855 6417 DEBUG tacker.openstack.common.service [-] database.max_overflow = 20 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.856 6417 DEBUG tacker.openstack.common.service [-] database.max_pool_size = 10 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.856 6417 DEBUG tacker.openstack.common.service [-] database.max_retries = 10 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.856 6417 DEBUG tacker.openstack.common.service [-] database.min_pool_size = 1 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.856 6417 DEBUG tacker.openstack.common.service [-] database.mysql_sql_mode = TRADITIONAL log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.856 6417 DEBUG tacker.openstack.common.service [-] database.pool_timeout = 10 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.856 6417 DEBUG tacker.openstack.common.service [-] database.retry_interval = 10 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.856 6417 DEBUG tacker.openstack.common.service [-] database.sqlite_db = log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.856 6417 DEBUG tacker.openstack.common.service [-] database.sqlite_synchronous = True log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.857 6417 DEBUG tacker.openstack.common.service [-] database.use_db_reconnect = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.857 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_notifications.driver = ['tacker.openstack.common.notifier.rpc_notifier'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.857 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_notifications.topics = ['notifications'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.857 6417 DEBUG tacker.openstack.common.service [-] oslo_messaging_notifications.transport_url = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.857 6417 DEBUG tacker.openstack.common.service [-] monitor_http_ping.port = 80 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.857 6417 DEBUG tacker.openstack.common.service [-] monitor_http_ping.retry = 5 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.857 6417 DEBUG tacker.openstack.common.service [-] monitor_http_ping.timeout = 1 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.858 6417 DEBUG tacker.openstack.common.service [-] vim_keys.openstack = /etc/tacker/vim/fernet_keys log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.858 6417 DEBUG tacker.openstack.common.service [-] tacker.boot_wait = 30 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.858 6417 DEBUG tacker.openstack.common.service [-] tacker.infra_driver = ['nova', 'heat', 'noop'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.858 6417 DEBUG tacker.openstack.common.service [-] tacker.mgmt_driver = ['noop', 'openwrt'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.858 6417 DEBUG tacker.openstack.common.service [-] tacker.monitor_driver = ['ping', 'http_ping'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.858 6417 DEBUG tacker.openstack.common.service [-] oslo_concurrency.disable_process_locking = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.859 6417 DEBUG tacker.openstack.common.service [-] oslo_concurrency.lock_path = /var/lib/tacker/lock log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.859 6417 DEBUG tacker.openstack.common.service [-] tacker_nova.auth_plugin = password log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.859 6417 DEBUG tacker.openstack.common.service [-] tacker_nova.auth_section = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.859 6417 DEBUG tacker.openstack.common.service [-] tacker_nova.cafile = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.859 6417 DEBUG tacker.openstack.common.service [-] tacker_nova.certfile = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.859 6417 DEBUG tacker.openstack.common.service [-] tacker_nova.insecure = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.859 6417 DEBUG tacker.openstack.common.service [-] tacker_nova.keyfile = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.860 6417 DEBUG tacker.openstack.common.service [-] tacker_nova.region_name = RegionOne log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.860 6417 DEBUG tacker.openstack.common.service [-] tacker_nova.timeout = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.860 6417 DEBUG tacker.openstack.common.service [-] monitor_ping.count = 1 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.860 6417 DEBUG tacker.openstack.common.service [-] monitor_ping.interval = 1 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.860 6417 DEBUG tacker.openstack.common.service [-] monitor_ping.timeout = 1 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.860 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.admin_password = **** log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.860 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.admin_tenant_name = admin log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.861 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.admin_token = **** log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.861 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.admin_user = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.861 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.auth_admin_prefix = log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.861 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.auth_host = 127.0.0.1 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.861 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.auth_port = 35357 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.861 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.auth_protocol = https log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.861 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.auth_section = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.862 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.auth_type = password log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.862 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.auth_uri = http://controler:5000 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.862 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.auth_url = http://controler:35357 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.862 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.auth_version = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.862 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.cache = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.862 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.cafile = /opt/stack/data/ca-bundle.pem log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.862 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.certfile = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.862 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.check_revocations_for_cached = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.863 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.default_domain_id = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.863 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.default_domain_name = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.863 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.delay_auth_decision = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.863 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.domain_id = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.863 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.domain_name = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.863 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.enforce_token_bind = permissive log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.863 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.hash_algorithms = ['md5'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.864 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.http_connect_timeout = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.864 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.http_request_max_retries = 3 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.864 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.identity_uri = http://controler:5000 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.864 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.include_service_catalog = True log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.864 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.insecure = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.864 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.keyfile = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.865 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.memcache_pool_conn_get_timeout = 10 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.865 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.memcache_pool_dead_retry = 300 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.865 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.memcache_pool_maxsize = 10 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.865 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.memcache_pool_socket_timeout = 3 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.865 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.memcache_pool_unused_timeout = 60 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.865 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.memcache_secret_key = **** log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.865 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.memcache_security_strategy = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.866 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.memcache_use_advanced_pool = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.866 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.memcached_servers = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.866 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.password = **** log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.866 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.project_domain_id = 44afe88f79ca491ca47748539ac5796b log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.866 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.project_domain_name = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.866 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.project_id = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.866 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.project_name = service log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.867 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.region_name = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.867 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.revocation_cache_time = 10 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.867 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.signing_dir = /var/cache/tacker log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.867 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.token_cache_time = 300 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.867 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.trust_id = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.867 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.user_domain_id = 44afe88f79ca491ca47748539ac5796b log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.867 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.user_domain_name = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.867 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.user_id = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.868 6417 DEBUG tacker.openstack.common.service [-] keystone_authtoken.username = tacker log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.868 6417 DEBUG tacker.openstack.common.service [-] openwrt.password = log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.868 6417 DEBUG tacker.openstack.common.service [-] openwrt.user = root log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 20:00:29.868 6417 DEBUG tacker.openstack.common.service [-] ******************************************************************************** log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2527
2017-03-06 20:00:29.868 6417 INFO tacker.wsgi [-] (6417) wsgi starting up on http://10.139.4.100:9890

2017-03-06 20:02:34.672 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 38903)

2017-03-06 20:02:34.710 6417 WARNING keystonemiddleware.auth_token [-] Using the in-process token cache is deprecated as of the 4.2.0 release and may be removed in the 5.0.0 release or the 'O' development cycle. The in-process cache causes inconsistent results and high memory usage. When the feature is removed the auth_token middleware will not cache tokens by default which may result in performance issues. It is recommended to use memcache for the auth_token token cache by setting the memcached_servers option.
2017-03-06 20:02:34.714 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 20:02:34.718 6417 DEBUG keystoneauth.session [-] REQ: curl -g -i --cacert "/opt/stack/data/ca-bundle.pem" -X GET http://controler:35357 -H "Accept: application/json" -H "User-Agent: tacker/0.3.2.dev10 keystonemiddleware.auth_token/4.4.1 keystoneauth1/2.19.0 python-requests/2.13.0 CPython/2.7.6" _http_log_request /usr/local/lib/python2.7/dist-packages/keystoneauth1/session.py:347
2017-03-06 20:02:34.758 6417 DEBUG requests.packages.urllib3.connectionpool [-] Starting new HTTP connection (1): controler _new_conn /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:207
2017-03-06 20:02:34.765 6417 DEBUG requests.packages.urllib3.connectionpool [-] http://controler:35357 "GET / HTTP/1.1" 300 589 _make_request /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:395
2017-03-06 20:02:34.824 6417 DEBUG keystoneauth.session [-] RESP: [300] Date: Mon, 06 Mar 2017 14:32:34 GMT Server: Apache/2.4.7 (Ubuntu) Vary: X-Auth-Token X-Distribution: Ubuntu Content-Length: 589 Keep-Alive: timeout=5, max=100 Connection: Keep-Alive Content-Type: application/json
RESP BODY: {"versions": {"values": [{"status": "stable", "updated": "2016-04-04T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id": "v3.6", "links": [{"href": "http://controler:35357/v3/", "rel": "self"}]}, {"status": "stable", "updated": "2014-04-17T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v2.0+json"}], "id": "v2.0", "links": [{"href": "http://controler:35357/v2.0/", "rel": "self"}, {"href": "http://docs.openstack.org/", "type": "text/html", "rel": "describedby"}]}]}}
 _http_log_response /usr/local/lib/python2.7/dist-packages/keystoneauth1/session.py:395
2017-03-06 20:02:34.824 6417 DEBUG keystoneauth.identity.v3.base [-] Making authentication request to http://controler:35357/v3/auth/tokens get_auth_ref /usr/local/lib/python2.7/dist-packages/keystoneauth1/identity/v3/base.py:165
2017-03-06 20:02:35.031 6417 DEBUG requests.packages.urllib3.connectionpool [-] http://controler:35357 "POST /v3/auth/tokens HTTP/1.1" 201 5154 _make_request /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:395
2017-03-06 20:02:35.033 6417 DEBUG keystoneauth.identity.v3.base [-] {"token": {"methods": ["password"], "roles": [{"id": "71a4e83e07624c508679db8ee4ecc275", "name": "admin"}], "expires_at": "2017-03-06T15:32:35.027940Z", "project": {"domain": {"id": "44afe88f79ca491ca47748539ac5796b", "name": "default"}, "id": "052de98620b64c10be3e2095584708a2", "name": "service"}, "catalog": [{"endpoints": [{"url": "http://controler:8777", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "06a2ebac1fb44e2a80a7eb0ea853743a"}, {"url": "http://controler:8777", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "1c83ab02d0544d1d9c97f8a9a763c2c6"}, {"url": "http://controler:8777", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "475689f2014d4d9c8831d574061c9199"}], "type": "metering", "id": "2616a8788a0140cb87c05f8ba315f5d5", "name": "ceilometer"}, {"endpoints": [{"url": "http://10.139.4.100:9890", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "3ede3c79370d4615ae575d0ae3e793ef"}, {"url": "http://10.139.4.100:9890", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "7ff22332505546d587a9ab1783a2ce88"}, {"url": "http://10.139.4.100:9890/", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "dfa0aaa1753f4504ad849dbf1a15b504"}], "type": "nfv-orchestration", "id": "29413625ad8d4f54a359ad8004ca4fd1", "name": "tacker"}, {"endpoints": [{"url": "http://controler:9292", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "189c9ccba64b447fa49fc70df1892358"}, {"url": "http://controler:9292", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "2b1ce4b2d48c4e3cb0c747adfeb2909a"}, {"url": "http://controler:9292", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "c501882747cd4c2380eaaed27621d5e1"}], "type": "image", "id": "8906e6942827476baad1b160d49ff75a", "name": "glance"}, {"endpoints": [{"url": "http://controler:8004/v1/052de98620b64c10be3e2095584708a2", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "35058257e2374ec19cc0c6c9ce65163c"}, {"url": "http://controler:8004/v1/052de98620b64c10be3e2095584708a2", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "afa8753d36124bccaf3ef74d6d68648b"}, {"url": "http://controler:8004/v1/052de98620b64c10be3e2095584708a2", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "e7d5915178a74137841660b45f06672e"}], "type": "orchestration", "id": "aebfea33f4b74230be0e96104e0cde15", "name": "heat"}, {"endpoints": [{"url": "http://controler:9696", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "3ed08201ee4a44e8b17426a065341cb6"}, {"url": "http://controler:9696", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "3f3e892055954cce85937d999ec00321"}, {"url": "http://controler:9696", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "edeeeab56c014b2fb156f094426ae002"}], "type": "network", "id": "c08d1790831e4a6eadfe934a37da948e", "name": "neutron"}, {"endpoints": [{"url": "http://controler:35357/v2.0", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "1d314c19d472472c887cdfb533b68e7c"}, {"url": "http://controler:5000/v2.0", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "a77a5acbadbc4588b38e4ee733d8449f"}, {"url": "http://controler:5000/v2.0", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "fd1ed4987c784761a4c2e35f01f2fab0"}], "type": "identity", "id": "ca417bc0cb7645d98bbf182623cc1b8f", "name": "keystone"}, {"endpoints": [{"url": "http://controler:8774/v2.1/052de98620b64c10be3e2095584708a2", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "091ccc1cf7fb4d709f116d85efa5ce2c"}, {"url": "http://controler:8774/v2.1/052de98620b64c10be3e2095584708a2", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "6d5090da2951408aadfbe8e8a0db5f13"}, {"url": "http://controler:8774/v2.1/052de98620b64c10be3e2095584708a2", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "85cec26f36a54f25b5c98477b13b0d0d"}], "type": "compute", "id": "d636f8bd6ee141d3a9cafcfa6a73957a", "name": "nova"}, {"endpoints": [{"url": "http://controler:8000/v1", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "3406ab08617a47e7846faab161d798b8"}, {"url": "http://controler:8000/v1", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "881f1809c0ce49e08045fa0798fde99e"}, {"url": "http://controler:8000/v1", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "bc5168a483c64fc498a465f40cda5c4e"}], "type": "cloudformation", "id": "fa06c529d38e49a0a5bfbd53c34c4a85", "name": "heat-cfn"}], "user": {"domain": {"id": "44afe88f79ca491ca47748539ac5796b", "name": "default"}, "id": "4aeabb5062004ceeaf4521f8a14f4bb2", "name": "tacker"}, "audit_ids": ["oi4t8-qjRuq4Yk0woWtLnw"], "issued_at": "2017-03-06T14:32:35.000000Z"}} get_auth_ref /usr/local/lib/python2.7/dist-packages/keystoneauth1/identity/v3/base.py:170
2017-03-06 20:02:35.034 6417 DEBUG keystoneauth.session [-] REQ: curl -g -i --cacert "/opt/stack/data/ca-bundle.pem" -X GET http://controler:35357/ -H "Accept: application/json" -H "User-Agent: tacker/0.3.2.dev10 keystonemiddleware.auth_token/4.4.1 keystoneauth1/2.19.0 python-requests/2.13.0 CPython/2.7.6" _http_log_request /usr/local/lib/python2.7/dist-packages/keystoneauth1/session.py:347
2017-03-06 20:02:35.041 6417 DEBUG requests.packages.urllib3.connectionpool [-] http://controler:35357 "GET / HTTP/1.1" 300 589 _make_request /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:395
2017-03-06 20:02:35.042 6417 DEBUG keystoneauth.session [-] RESP: [300] Date: Mon, 06 Mar 2017 14:32:35 GMT Server: Apache/2.4.7 (Ubuntu) Vary: X-Auth-Token X-Distribution: Ubuntu Content-Length: 589 Keep-Alive: timeout=5, max=98 Connection: Keep-Alive Content-Type: application/json
RESP BODY: {"versions": {"values": [{"status": "stable", "updated": "2016-04-04T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v3+json"}], "id": "v3.6", "links": [{"href": "http://controler:35357/v3/", "rel": "self"}]}, {"status": "stable", "updated": "2014-04-17T00:00:00Z", "media-types": [{"base": "application/json", "type": "application/vnd.openstack.identity-v2.0+json"}], "id": "v2.0", "links": [{"href": "http://controler:35357/v2.0/", "rel": "self"}, {"href": "http://docs.openstack.org/", "type": "text/html", "rel": "describedby"}]}]}}
 _http_log_response /usr/local/lib/python2.7/dist-packages/keystoneauth1/session.py:395
2017-03-06 20:02:35.042 6417 DEBUG keystonemiddleware.auth_token [-] Auth Token confirmed use of None apis _get_strategy_class /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/_identity.py:190
2017-03-06 20:02:35.044 6417 DEBUG keystoneauth.session [-] REQ: curl -g -i --cacert "/opt/stack/data/ca-bundle.pem" -X GET http://controler:35357/v3/auth/tokens -H "X-Subject-Token: {SHA1}6c7eb9b9042cb33ccfcfe3cb79da9fbede19796e" -H "User-Agent: python-keystoneclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}9667388f852e0dd8f46b6cecf820dd38b7cff579" _http_log_request /usr/local/lib/python2.7/dist-packages/keystoneauth1/session.py:347
2017-03-06 20:02:35.296 6417 DEBUG requests.packages.urllib3.connectionpool [-] http://controler:35357 "GET /v3/auth/tokens HTTP/1.1" 200 5246 _make_request /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:395
2017-03-06 20:02:35.420 6417 DEBUG keystoneauth.session [-] RESP: [200] Date: Mon, 06 Mar 2017 14:32:35 GMT Server: Apache/2.4.7 (Ubuntu) X-Subject-Token: {SHA1}6c7eb9b9042cb33ccfcfe3cb79da9fbede19796e Vary: X-Auth-Token X-Distribution: Ubuntu x-openstack-request-id: req-742a82f2-161f-4045-9bcf-7c18f1ecd08a Content-Length: 5246 Keep-Alive: timeout=5, max=97 Connection: Keep-Alive Content-Type: application/json
RESP BODY: {"token": {"methods": ["token", "password"], "roles": [{"id": "71a4e83e07624c508679db8ee4ecc275", "name": "admin"}, {"id": "10e802b95f3f4b45a7384fea17438681", "name": "user"}], "expires_at": "2017-03-06T15:31:06.452854Z", "project": {"domain": {"id": "44afe88f79ca491ca47748539ac5796b", "name": "default"}, "id": "1dfdb8d3adc64559a2870bb086c441b6", "name": "admin"}, "catalog": "<removed>", "user": {"domain": {"id": "44afe88f79ca491ca47748539ac5796b", "name": "default"}, "id": "9fe0f2888cc343fb84e75fcacbe6c53d", "name": "admin"}, "audit_ids": ["dYiykQQuS2muMZXsMC8tmA", "s6Sn_XPlST2_ghuPep8w2A"], "issued_at": "2017-03-06T14:31:14.000000Z"}}
 _http_log_response /usr/local/lib/python2.7/dist-packages/keystoneauth1/session.py:395
2017-03-06 20:02:35.420 6417 DEBUG keystoneauth.session [-] GET call to identity for http://controler:35357/v3/auth/tokens used request id req-742a82f2-161f-4045-9bcf-7c18f1ecd08a request /usr/local/lib/python2.7/dist-packages/keystoneauth1/session.py:640
2017-03-06 20:02:35.420 6417 DEBUG keystonemiddleware.auth_token [-] Storing token in cache store /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/_cache.py:149
2017-03-06 20:02:35.421 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 20:02:35.422 6417 DEBUG tacker.common.utils [-] Reloading cached file /usr/local/etc/tacker/policy.json read_cached_file /usr/local/lib/python2.7/dist-packages/tacker/common/utils.py:144
2017-03-06 20:02:35.424 6417 DEBUG tacker.policy [-] Loading policies from file: /usr/local/etc/tacker/policy.json _set_rules /usr/local/lib/python2.7/dist-packages/tacker/policy.py:89
2017-03-06 20:02:35.433 6417 DEBUG routes.middleware [-] Matched GET /vnfds.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 20:02:35.433 6417 DEBUG routes.middleware [-] Route path: '/vnfds.:(format)', defaults: {'action': u'index', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 20:02:35.433 6417 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>, 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 20:02:35.474 6417 INFO tacker.wsgi [req-23655536-5fa2-4909-90b5-3d50871ad6bd None] 10.139.4.100 - - [06/Mar/2017 20:02:35] "GET /v1.0/vnfds.json HTTP/1.1" 200 988 0.780570

2017-03-06 20:02:39.967 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 38912)

2017-03-06 20:02:39.968 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 20:02:39.969 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 20:02:39.970 6417 DEBUG routes.middleware [-] Matched GET /vnfds/a4e93c57-e536-4c3a-9d84-d00ea4ff2777.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 20:02:39.970 6417 DEBUG routes.middleware [-] Route path: '/vnfds/:(id).:(format)', defaults: {'action': u'show', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 20:02:39.970 6417 DEBUG routes.middleware [-] Match dict: {'action': u'show', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>, 'id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 20:02:39.977 6417 INFO tacker.wsgi [req-d343e55a-9f7e-4b95-844e-809dc778815c None] 10.139.4.100 - - [06/Mar/2017 20:02:39] "GET /v1.0/vnfds/a4e93c57-e536-4c3a-9d84-d00ea4ff2777.json HTTP/1.1" 200 985 0.008643

2017-03-06 20:02:47.421 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 38920)

2017-03-06 20:02:47.422 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 20:02:47.424 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 20:02:47.425 6417 DEBUG routes.middleware [-] Matched GET /vnfs.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 20:02:47.425 6417 DEBUG routes.middleware [-] Route path: '/vnfs.:(format)', defaults: {'action': u'index', 'controller': <wsgify at 140247309049232 wrapping <function resource at 0x7f8ddf097230>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 20:02:47.426 6417 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 140247309049232 wrapping <function resource at 0x7f8ddf097230>>, 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 20:02:47.449 6417 INFO tacker.wsgi [req-4d6ab580-86ad-4896-a101-8eec2591d908 None] 10.139.4.100 - - [06/Mar/2017 20:02:47] "GET /v1.0/vnfs.json HTTP/1.1" 200 225 0.026685

2017-03-06 20:02:51.721 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 38928)

2017-03-06 20:02:51.722 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 20:02:51.724 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 20:02:51.724 6417 DEBUG routes.middleware [-] Matched GET /vnfds.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 20:02:51.725 6417 DEBUG routes.middleware [-] Route path: '/vnfds.:(format)', defaults: {'action': u'index', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 20:02:51.725 6417 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>, 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 20:02:51.731 6417 INFO tacker.wsgi [req-e6fe1e04-ca63-40eb-99dc-1469e375b474 None] 10.139.4.100 - - [06/Mar/2017 20:02:51] "GET /v1.0/vnfds.json HTTP/1.1" 200 988 0.009467

2017-03-06 20:02:51.735 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 38929)

2017-03-06 20:02:51.736 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 20:02:51.737 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 20:02:51.738 6417 DEBUG routes.middleware [-] Matched GET /vims.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 20:02:51.738 6417 DEBUG routes.middleware [-] Route path: '/vims.:(format)', defaults: {'action': u'index', 'controller': <wsgify at 140247309049744 wrapping <function resource at 0x7f8ddf097488>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 20:02:51.738 6417 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 140247309049744 wrapping <function resource at 0x7f8ddf097488>>, 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 20:02:51.749 6417 INFO tacker.wsgi [req-090802bb-2a55-4d6d-a9ee-7a49503586c8 None] 10.139.4.100 - - [06/Mar/2017 20:02:51] "GET /v1.0/vims.json HTTP/1.1" 200 861 0.012653

2017-03-06 20:03:17.434 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 38932)

2017-03-06 20:03:17.435 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 20:03:17.436 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 20:03:17.437 6417 DEBUG routes.middleware [-] Matched GET /vnfds.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 20:03:17.437 6417 DEBUG routes.middleware [-] Route path: '/vnfds.:(format)', defaults: {'action': u'index', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 20:03:17.437 6417 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>, 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 20:03:17.446 6417 INFO tacker.wsgi [req-1ca82929-ab5a-4a08-a521-7151d84c92c4 None] 10.139.4.100 - - [06/Mar/2017 20:03:17] "GET /v1.0/vnfds.json HTTP/1.1" 200 988 0.011135

2017-03-06 20:03:17.448 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 38933)

2017-03-06 20:03:17.449 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 20:03:17.450 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 20:03:17.451 6417 DEBUG routes.middleware [-] Matched GET /vims.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 20:03:17.451 6417 DEBUG routes.middleware [-] Route path: '/vims.:(format)', defaults: {'action': u'index', 'controller': <wsgify at 140247309049744 wrapping <function resource at 0x7f8ddf097488>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 20:03:17.451 6417 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 140247309049744 wrapping <function resource at 0x7f8ddf097488>>, 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 20:03:17.456 6417 INFO tacker.wsgi [req-881cae67-7ef4-49f2-a077-a67977e49160 None] 10.139.4.100 - - [06/Mar/2017 20:03:17] "GET /v1.0/vims.json HTTP/1.1" 200 861 0.007065

2017-03-06 20:03:17.458 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 38934)

2017-03-06 20:03:17.459 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 20:03:17.460 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 20:03:17.460 6417 DEBUG routes.middleware [-] Matched POST /vnfs.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 20:03:17.461 6417 DEBUG routes.middleware [-] Route path: '/vnfs.:(format)', defaults: {'action': u'create', 'controller': <wsgify at 140247309049232 wrapping <function resource at 0x7f8ddf097230>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 20:03:17.461 6417 DEBUG routes.middleware [-] Match dict: {'action': u'create', 'controller': <wsgify at 140247309049232 wrapping <function resource at 0x7f8ddf097230>>, 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 20:03:17.461 6417 DEBUG tacker.api.v1.base [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] Request body: {u'vnf': {u'attributes': {}, u'vim_id': u'aed4074f-7df2-424e-87b1-d013aeb50e7d', u'vnfd_id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', u'name': u'vnftest22'}, u'placement_attr': {u'RegionOne': u'RegionOne'}} prepare_request_body /usr/local/lib/python2.7/dist-packages/tacker/api/v1/base.py:509
2017-03-06 20:03:17.466 6417 DEBUG tacker.vm.vim_client [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] VIM info found for vim id aed4074f-7df2-424e-87b1-d013aeb50e7d get_vim /usr/local/lib/python2.7/dist-packages/tacker/vm/vim_client.py:62
2017-03-06 20:03:17.466 6417 DEBUG tacker.vm.vim_client [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] VIM id is aed4074f-7df2-424e-87b1-d013aeb50e7d _build_vim_auth /usr/local/lib/python2.7/dist-packages/tacker/vm/vim_client.py:77
2017-03-06 20:03:17.467 6417 DEBUG tacker.vm.vim_client [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] Attempting to open key file for vim id aed4074f-7df2-424e-87b1-d013aeb50e7d _find_vim_key /usr/local/lib/python2.7/dist-packages/tacker/vm/vim_client.py:101
2017-03-06 20:03:17.484 6417 DEBUG tacker.db.vm.vm_db [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] device {'description': '', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', u'vim_id': u'aed4074f-7df2-424e-87b1-d013aeb50e7d', 'placement_attr': {'vim_name': u'localdev'}, u'attributes': {}, 'template_id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', u'name': u'vnftest22'} _create_device_pre /usr/local/lib/python2.7/dist-packages/tacker/db/vm/vm_db.py:342
2017-03-06 20:03:17.509 6417 DEBUG tacker.db.vm.vm_db [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] device_db <tacker.db.vm.vm_db.Device[object at 7f8ddeca4cd0] {tenant_id=u'1dfdb8d3adc64559a2870bb086c441b6', id='6dd637dd-684b-45e1-b343-488c70f1acef', template_id=u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', name=u'vnftest22', description=u'demo-example', instance_id=None, mgmt_url=None, status='PENDING_CREATE', vim_id=u'aed4074f-7df2-424e-87b1-d013aeb50e7d', placement_attr={'vim_name': u'localdev'}}> _make_device_dict /usr/local/lib/python2.7/dist-packages/tacker/db/vm/vm_db.py:193
2017-03-06 20:03:17.519 6417 DEBUG tacker.db.vm.vm_db [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] device_db attributes [] _make_device_dict /usr/local/lib/python2.7/dist-packages/tacker/db/vm/vm_db.py:194
2017-03-06 20:03:17.523 6417 DEBUG tacker.vm.plugin [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] device_dict {'status': 'PENDING_CREATE', 'device_template': {'service_types': [{'service_type': u'vnfd', 'id': u'ae2cc76c-8b4f-43c7-8471-7dcd15cc95eb'}], 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'mgmt_driver': u'noop', 'infra_driver': u'heat', 'attributes': {u'vnfd': u'template_name: sample-vnfd\ndescription: demo-example\n\nservice_properties:\n Id: sample-vnfd\n vendor: tacker\n version: 1\n\nvdus:\n vdu1:\n id: vdu1\n vm_image: Cirros\n instance_type: m1.tiny\n\n network_interfaces:\n management:\n network: 7918b3b3-6810-435b-970c-7e3e68f6c439\n management: true\n\n placement_policy:\n availability_zone: nova\n\n config:\n param0: key0\n param1: key1\n'}, 'id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'testvnf1'}, 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'vim_id': u'aed4074f-7df2-424e-87b1-d013aeb50e7d', 'id': '6dd637dd-684b-45e1-b343-488c70f1acef', 'instance_id': None, 'mgmt_url': None, 'placement_attr': {'vim_name': u'localdev'}, 'attributes': {}, 'template_id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'vnftest22'} _create_device /usr/local/lib/python2.7/dist-packages/tacker/vm/plugin.py:254
2017-03-06 20:03:17.658 6417 DEBUG tacker.common.log [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] tacker.vm.infra_drivers.heat.heat.DeviceHeat method create called with arguments () {'device': {'status': 'PENDING_CREATE', 'instance_id': None, 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'vim_id': u'aed4074f-7df2-424e-87b1-d013aeb50e7d', 'template_id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'device_template': {'service_types': [{'service_type': u'vnfd', 'id': u'ae2cc76c-8b4f-43c7-8471-7dcd15cc95eb'}], 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'mgmt_driver': u'noop', 'infra_driver': u'heat', 'attributes': {u'vnfd': u'template_name: sample-vnfd\ndescription: demo-example\n\nservice_properties:\n Id: sample-vnfd\n vendor: tacker\n version: 1\n\nvdus:\n vdu1:\n id: vdu1\n vm_image: Cirros\n instance_type: m1.tiny\n\n network_interfaces:\n management:\n network: 7918b3b3-6810-435b-970c-7e3e68f6c439\n management: true\n\n placement_policy:\n availability_zone: nova\n\n config:\n param0: key0\n param1: key1\n'}, 'id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'testvnf1'}, 'mgmt_url': None, 'placement_attr': {'vim_name': u'localdev'}, 'attributes': {}, 'id': '6dd637dd-684b-45e1-b343-488c70f1acef', 'name': u'vnftest22'}, 'auth_attr': {u'username': u'admin', 'password': 'tcs#1234', 'project_name': u'admin', u'user_domain_name': u'default', 'auth_url': u'http://10.139.4.100:5000/v3', 'project_id': None, 'project_domain_name': u'default'}, 'context': <tacker.context.Context object at 0x7f8ddeca4c10>, 'plugin': <tacker.vm.plugin.VNFMPlugin object at 0x7f8ddf5f3b50>} wrapper /usr/local/lib/python2.7/dist-packages/tacker/common/log.py:32
2017-03-06 20:03:17.665 6417 DEBUG tacker.vm.infra_drivers.heat.heat [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] device {'status': 'PENDING_CREATE', 'device_template': {'service_types': [{'service_type': u'vnfd', 'id': u'ae2cc76c-8b4f-43c7-8471-7dcd15cc95eb'}], 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'mgmt_driver': u'noop', 'infra_driver': u'heat', 'attributes': {u'vnfd': u'template_name: sample-vnfd\ndescription: demo-example\n\nservice_properties:\n Id: sample-vnfd\n vendor: tacker\n version: 1\n\nvdus:\n vdu1:\n id: vdu1\n vm_image: Cirros\n instance_type: m1.tiny\n\n network_interfaces:\n management:\n network: 7918b3b3-6810-435b-970c-7e3e68f6c439\n management: true\n\n placement_policy:\n availability_zone: nova\n\n config:\n param0: key0\n param1: key1\n'}, 'id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'testvnf1'}, 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'vim_id': u'aed4074f-7df2-424e-87b1-d013aeb50e7d', 'id': '6dd637dd-684b-45e1-b343-488c70f1acef', 'instance_id': None, 'mgmt_url': None, 'placement_attr': {'vim_name': u'localdev'}, 'attributes': {}, 'template_id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'vnftest22'} create /usr/local/lib/python2.7/dist-packages/tacker/vm/infra_drivers/heat/heat.py:257
2017-03-06 20:03:17.666 6417 DEBUG keystoneclient.auth.identity.v3.base [-] Making authentication request to http://10.139.4.100:5000/v3/auth/tokens get_auth_ref /usr/lib/python2.7/dist-packages/keystoneclient/auth/identity/v3/base.py:188
2017-03-06 20:03:17.670 6417 DEBUG requests.packages.urllib3.connectionpool [-] Starting new HTTP connection (1): 10.139.4.100 _new_conn /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:207
2017-03-06 20:03:17.855 6417 DEBUG requests.packages.urllib3.connectionpool [-] http://10.139.4.100:5000 "POST /v3/auth/tokens HTTP/1.1" 201 5211 _make_request /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:395
2017-03-06 20:03:17.862 6417 DEBUG keystoneclient.session [-] REQ: curl -g -i -X GET http://controler:8004/v1/1dfdb8d3adc64559a2870bb086c441b6/resource_types/OS%3A%3ANeutron%3A%3APort -H "User-Agent: python-heatclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}a282978d0bfe55f835c5966857ef4f4aa2cee48f" _http_log_request /usr/lib/python2.7/dist-packages/keystoneclient/session.py:206
2017-03-06 20:03:17.864 6417 DEBUG requests.packages.urllib3.connectionpool [-] Starting new HTTP connection (1): controler _new_conn /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:207
2017-03-06 20:03:19.917 6417 DEBUG requests.packages.urllib3.connectionpool [-] http://controler:8004 "GET /v1/1dfdb8d3adc64559a2870bb086c441b6/resource_types/OS%3A%3ANeutron%3A%3APort HTTP/1.1" 200 6165 _make_request /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:395
2017-03-06 20:03:19.919 6417 DEBUG keystoneclient.session [-] RESP: [200] Content-Type: application/json; charset=UTF-8 Content-Length: 6165 X-Openstack-Request-Id: req-5ee8e843-53bd-4d1a-b732-a6e1ef152ca1 Date: Mon, 06 Mar 2017 14:33:19 GMT Connection: keep-alive
RESP BODY: {"support_status": {"status": "SUPPORTED", "message": null, "version": null, "previous_status": null}, "attributes": {"status": {"type": "string", "description": "The status of the port."}, "subnets": {"type": "list", "description": "A list of all subnet attributes for the port."}, "name": {"type": "string", "description": "Friendly name of the port."}, "allowed_address_pairs": {"type": "list", "description": "Additional MAC/IP address pairs allowed to pass through a port."}, "admin_state_up": {"type": "string", "description": "The administrative state of this port."}, "network_id": {"type": "string", "description": "Unique identifier for the network owning the port."}, "tenant_id": {"type": "string", "description": "Tenant owning the port."}, "show": {"type": "map", "description": "Detailed information about resource."}, "device_owner": {"type": "string", "description": "Name of the network owning the port."}, "qos_policy_id": {"type": "string", "description": "The QoS policy ID attached to this port."}, "mac_address": {"type": "string", "description": "MAC address of the port."}, "port_security_enabled": {"type": "boolean", "description": "Port security enabled of the port."}, "fixed_ips": {"type": "list", "description": "Fixed IP addresses."}, "security_groups": {"type": "list", "description": "A list of security groups for the port."}, "device_id": {"type": "string", "description": "Unique identifier for the device."}}, "properties": {"replacement_policy": {"description": "Policy on how to respond to a stack-update for this resource. REPLACE_ALWAYS will replace the port regardless of any property changes. AUTO will update the existing port for any changed update-allowed property.", "default": "AUTO", "required": false, "update_allowed": true, "type": "string", "immutable": false, "constraints": [{"allowed_values": ["REPLACE_ALWAYS", "AUTO"]}]}, "name": {"update_allowed": true, "required": false, "type": "string", "description": "A symbolic name for this port.", "immutable": false}, "allowed_address_pairs": {"description": "Additional MAC/IP address pairs allowed to pass through the port.", "required": false, "update_allowed": false, "type": "list", "immutable": false, "schema": {"*": {"update_allowed": false, "required": false, "type": "map", "immutable": false, "schema": {"ip_address": {"description": "IP address to allow through this port.", "required": true, "update_allowed": false, "type": "string", "immutable": false, "constraints": [{"custom_constraint": "net_cidr"}]}, "mac_address": {"description": "MAC address to allow through this port.", "required": false, "update_allowed": false, "type": "string", "immutable": false, "constraints": [{"custom_constraint": "mac_addr"}]}}}}}, "admin_state_up": {"description": "The administrative state of this port.", "default": true, "required": false, "update_allowed": true, "type": "boolean", "immutable": false}, "binding:vnic_type": {"description": "The vnic type to be bound on the neutron port. To support SR-IOV PCI passthrough networking, you can request that the neutron port to be realized as normal (virtual nic), direct (pci passthrough), or macvtap (virtual interface with a tap-like software interface). Note that this only works for Neutron deployments that support the bindings extension.", "required": false, "update_allowed": true, "type": "string", "immutable": false, "constraints": [{"allowed_values": ["normal", "direct", "macvtap"]}]}, "device_owner": {"update_allowed": true, "required": false, "type": "string", "description": "Name of the network owning the port. The value is typically network:floatingip or network:router_interface or network:dhcp.", "immutable": false}, "value_specs": {"description": "Extra parameters to include in the request.", "default": {}, "required": false, "update_allowed": true, "type": "map", "immutable": false}, "mac_address": {"description": "MAC address to give to this port.", "required": false, "update_allowed": false, "type": "string", "immutable": false, "constraints": [{"custom_constraint": "mac_addr"}]}, "port_security_enabled": {"update_allowed": true, "required": false, "type": "boolean", "description": "Flag to enable/disable port security on the port. When disable this feature(set it to False), there will be no packages filtering, like security-group and address-pairs.", "immutable": false}, "qos_policy": {"description": "The name or ID of QoS policy to attach to this port.", "required": false, "update_allowed": true, "type": "string", "immutable": false, "constraints": [{"custom_constraint": "neutron.qos_policy"}]}, "device_id": {"update_allowed": true, "required": false, "type": "string", "description": "Device ID of this port.", "immutable": false}, "fixed_ips": {"description": "Desired IPs for this port.", "required": false, "update_allowed": true, "type": "list", "immutable": false, "schema": {"*": {"update_allowed": false, "required": false, "type": "map", "immutable": false, "schema": {"subnet_id": {"update_allowed": false, "required": false, "type": "string", "immutable": false, "constraints": [{"custom_constraint": "neutron.subnet"}]}, "subnet": {"description": "Subnet in which to allocate the IP address for this port.", "required": false, "update_allowed": false, "type": "string", "immutable": false, "constraints": [{"custom_constraint": "neutron.subnet"}]}, "ip_address": {"description": "IP address desired in the subnet for this port.", "required": false, "update_allowed": false, "type": "string", "immutable": false, "constraints": [{"custom_constraint": "ip_addr"}]}}}}}, "security_groups": {"update_allowed": true, "required": false, "type": "list", "description": "Security group IDs to associate with this port.", "immutable": false}, "network": {"description": "Network this port belongs to. If you plan to use current port to assign Floating IP, you should specify fixed_ips with subnet. Note if this changes to a different network update, the port will be replaced.", "required": true, "update_allowed": false, "type": "string", "immutable": false, "constraints": [{"custom_constraint": "neutron.network"}]}}, "resource_type": "OS::Neutron::Port"}
 _http_log_response /usr/lib/python2.7/dist-packages/keystoneclient/session.py:231
2017-03-06 20:03:19.920 6417 DEBUG tacker.vm.infra_drivers.heat.heat [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] vnfd_yaml template_name: sample-vnfd
description: demo-example

service_properties:
  Id: sample-vnfd
  vendor: tacker
  version: 1

vdus:
  vdu1:
    id: vdu1
    vm_image: Cirros
    instance_type: m1.tiny

    network_interfaces:
      management:
        network: 7918b3b3-6810-435b-970c-7e3e68f6c439
        management: true

    placement_policy:
      availability_zone: nova

    config:
      param0: key0
      param1: key1
 create /usr/local/lib/python2.7/dist-packages/tacker/vm/infra_drivers/heat/heat.py:282
2017-03-06 20:03:19.924 6417 DEBUG tacker.vm.infra_drivers.heat.heat [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] vnfd_dict OrderedDict([('template_name', 'sample-vnfd'), ('description', 'demo-example'), ('service_properties', OrderedDict([('Id', 'sample-vnfd'), ('vendor', 'tacker'), ('version', 1)])), ('vdus', OrderedDict([('vdu1', OrderedDict([('id', 'vdu1'), ('vm_image', 'Cirros'), ('instance_type', 'm1.tiny'), ('network_interfaces', OrderedDict([('management', OrderedDict([('network', '7918b3b3-6810-435b-970c-7e3e68f6c439'), ('management', True)]))])), ('placement_policy', OrderedDict([('availability_zone', 'nova')])), ('config', OrderedDict([('param0', 'key0'), ('param1', 'key1')]))]))]))]) create /usr/local/lib/python2.7/dist-packages/tacker/vm/infra_drivers/heat/heat.py:285
2017-03-06 20:03:19.925 6417 DEBUG tacker.common.log [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] tacker.vm.infra_drivers.heat.heat.DeviceHeat method _process_vdu_network_interfaces called with arguments ('vdu1', OrderedDict([('id', 'vdu1'), ('vm_image', 'Cirros'), ('instance_type', 'm1.tiny'), ('network_interfaces', OrderedDict([('management', OrderedDict([('network', '7918b3b3-6810-435b-970c-7e3e68f6c439'), ('management', True)]))])), ('placement_policy', OrderedDict([('availability_zone', 'nova')])), ('config', OrderedDict([('param0', 'key0'), ('param1', 'key1')]))]), {'image': 'Cirros', 'flavor': 'm1.tiny'}, {'outputs': {}, 'heat_template_version': datetime.date(2013, 5, 23), 'description': 'demo-example', 'resources': {'vdu1': {'type': 'OS::Nova::Server', 'properties': {'image': 'Cirros', 'flavor': 'm1.tiny'}}}}, {}) {} wrapper /usr/local/lib/python2.7/dist-packages/tacker/common/log.py:32
2017-03-06 20:03:19.930 6417 DEBUG tacker.vm.infra_drivers.heat.heat [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] service_context: [] create /usr/local/lib/python2.7/dist-packages/tacker/vm/infra_drivers/heat/heat.py:407
2017-03-06 20:03:19.930 6417 DEBUG tacker.vm.infra_drivers.heat.heat [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] fields: {'stack_name': 'tacker.vm.infra_drivers.heat.heat_DeviceHeat-6dd637dd-684b-45e1-b343-488c70f1acef', 'template': 'description: demo-example\nheat_template_version: 2013-05-23\noutputs:\n mgmt_ip-vdu1:\n description: management ip address\n value:\n get_attr: [vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port, fixed_ips, 0, ip_address]\nresources:\n vdu1:\n properties:\n availability_zone: nova\n config_drive: true\n flavor: m1.tiny\n image: Cirros\n metadata: {param0: key0, param1: key1}\n networks:\n - port: {get_resource: vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port}\n type: OS::Nova::Server\n vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port:\n properties:\n fixed_ips: []\n network: 7918b3b3-6810-435b-970c-7e3e68f6c439\n port_security_enabled: false\n type: OS::Neutron::Port\n'} create /usr/local/lib/python2.7/dist-packages/tacker/vm/infra_drivers/heat/heat.py:409
2017-03-06 20:03:19.930 6417 DEBUG tacker.vm.infra_drivers.heat.heat [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] template: description: demo-example
heat_template_version: 2013-05-23
outputs:
  mgmt_ip-vdu1:
    description: management ip address
    value:
      get_attr: [vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port, fixed_ips, 0, ip_address]
resources:
  vdu1:
    properties:
      availability_zone: nova
      config_drive: true
      flavor: m1.tiny
      image: Cirros
      metadata: {param0: key0, param1: key1}
      networks:
      - port: {get_resource: vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port}
    type: OS::Nova::Server
  vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port:
    properties:
      fixed_ips: []
      network: 7918b3b3-6810-435b-970c-7e3e68f6c439
      port_security_enabled: false
    type: OS::Neutron::Port
 create /usr/local/lib/python2.7/dist-packages/tacker/vm/infra_drivers/heat/heat.py:410
2017-03-06 20:03:19.931 6417 DEBUG keystoneclient.session [-] REQ: curl -g -i -X POST http://controler:8004/v1/1dfdb8d3adc64559a2870bb086c441b6/stacks -H "User-Agent: python-heatclient" -H "Content-Type: application/json" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}a282978d0bfe55f835c5966857ef4f4aa2cee48f" -d '{"stack_name": "tacker.vm.infra_drivers.heat.heat_DeviceHeat-6dd637dd-684b-45e1-b343-488c70f1acef", "disable_rollback": true, "template": "description: demo-example\nheat_template_version: 2013-05-23\noutputs:\n mgmt_ip-vdu1:\n description: management ip address\n value:\n get_attr: [vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port, fixed_ips, 0, ip_address]\nresources:\n vdu1:\n properties:\n availability_zone: nova\n config_drive: true\n flavor: m1.tiny\n image: Cirros\n metadata: {param0: key0, param1: key1}\n networks:\n - port: {get_resource: vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port}\n type: OS::Nova::Server\n vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port:\n properties:\n fixed_ips: []\n network: 7918b3b3-6810-435b-970c-7e3e68f6c439\n port_security_enabled: false\n type: OS::Neutron::Port\n", "timeout_mins": 10}' _http_log_request /usr/lib/python2.7/dist-packages/keystoneclient/session.py:206
2017-03-06 20:03:20.828 6417 DEBUG requests.packages.urllib3.connectionpool [-] http://controler:8004 "POST /v1/1dfdb8d3adc64559a2870bb086c441b6/stacks HTTP/1.1" 400 348 _make_request /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:395
2017-03-06 20:03:20.829 6417 DEBUG keystoneclient.session [-] RESP: [400] Content-Type: application/json; charset=UTF-8 Content-Length: 348 X-Openstack-Request-Id: req-2fa31555-f388-4d15-8da4-6ba63e8a598b Date: Mon, 06 Mar 2017 14:33:20 GMT Connection: keep-alive
RESP BODY: {"explanation": "The server could not comply with the request since it is either malformed or otherwise incorrect.", "code": 400, "error": {"message": "Property error: : resources.vdu1.properties.image: : \"Cirros\" does not validate glance.image (constraint not found)", "traceback": null, "type": "StackValidationFailed"}, "title": "Bad Request"}
 _http_log_response /usr/lib/python2.7/dist-packages/keystoneclient/session.py:231
2017-03-06 20:03:20.840 6417 DEBUG tacker.db.vm.vm_db [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] device_db <tacker.db.vm.vm_db.Device[object at 7f8ddebae910] {tenant_id=u'1dfdb8d3adc64559a2870bb086c441b6', id=u'6dd637dd-684b-45e1-b343-488c70f1acef', template_id=u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', name=u'vnftest22', description=u'demo-example', instance_id=None, mgmt_url=None, status='PENDING_DELETE', vim_id=u'aed4074f-7df2-424e-87b1-d013aeb50e7d', placement_attr={'vim_name': u'localdev'}}> _make_device_dict /usr/local/lib/python2.7/dist-packages/tacker/db/vm/vm_db.py:193
2017-03-06 20:03:20.843 6417 DEBUG tacker.db.vm.vm_db [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] device_db attributes [] _make_device_dict /usr/local/lib/python2.7/dist-packages/tacker/db/vm/vm_db.py:194
2017-03-06 20:03:20.852 6417 DEBUG tacker.vm.vim_client [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] VIM info found for vim id aed4074f-7df2-424e-87b1-d013aeb50e7d get_vim /usr/local/lib/python2.7/dist-packages/tacker/vm/vim_client.py:62
2017-03-06 20:03:20.853 6417 DEBUG tacker.vm.vim_client [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] VIM id is aed4074f-7df2-424e-87b1-d013aeb50e7d _build_vim_auth /usr/local/lib/python2.7/dist-packages/tacker/vm/vim_client.py:77
2017-03-06 20:03:20.853 6417 DEBUG tacker.vm.vim_client [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] Attempting to open key file for vim id aed4074f-7df2-424e-87b1-d013aeb50e7d _find_vim_key /usr/local/lib/python2.7/dist-packages/tacker/vm/vim_client.py:101
2017-03-06 20:03:20.854 6417 DEBUG tacker.vm.monitor [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] deleting device_id 6dd637dd-684b-45e1-b343-488c70f1acef delete_hosting_vnf /usr/local/lib/python2.7/dist-packages/tacker/vm/monitor.py:112
2017-03-06 20:03:20.857 6417 DEBUG tacker.vm.mgmt_drivers.noop [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] mgmt_device_call {'status': 'PENDING_DELETE', 'device_template': {'service_types': [{'service_type': u'vnfd', 'id': u'ae2cc76c-8b4f-43c7-8471-7dcd15cc95eb'}], 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'mgmt_driver': u'noop', 'infra_driver': u'heat', 'attributes': {u'vnfd': u'template_name: sample-vnfd\ndescription: demo-example\n\nservice_properties:\n Id: sample-vnfd\n vendor: tacker\n version: 1\n\nvdus:\n vdu1:\n id: vdu1\n vm_image: Cirros\n instance_type: m1.tiny\n\n network_interfaces:\n management:\n network: 7918b3b3-6810-435b-970c-7e3e68f6c439\n management: true\n\n placement_policy:\n availability_zone: nova\n\n config:\n param0: key0\n param1: key1\n'}, 'id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'testvnf1'}, 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'vim_id': u'aed4074f-7df2-424e-87b1-d013aeb50e7d', 'id': u'6dd637dd-684b-45e1-b343-488c70f1acef', 'instance_id': None, 'mgmt_url': None, 'placement_attr': {'vim_name': u'localdev'}, 'attributes': {}, 'template_id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'vnftest22'} {'action': 'delete_device', 'kwargs': {'device': {'status': 'PENDING_DELETE', 'device_template': {'service_types': [{'service_type': u'vnfd', 'id': u'ae2cc76c-8b4f-43c7-8471-7dcd15cc95eb'}], 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'mgmt_driver': u'noop', 'infra_driver': u'heat', 'attributes': {u'vnfd': u'template_name: sample-vnfd\ndescription: demo-example\n\nservice_properties:\n Id: sample-vnfd\n vendor: tacker\n version: 1\n\nvdus:\n vdu1:\n id: vdu1\n vm_image: Cirros\n instance_type: m1.tiny\n\n network_interfaces:\n management:\n network: 7918b3b3-6810-435b-970c-7e3e68f6c439\n management: true\n\n placement_policy:\n availability_zone: nova\n\n config:\n param0: key0\n param1: key1\n'}, 'id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'testvnf1'}, 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'vim_id': u'aed4074f-7df2-424e-87b1-d013aeb50e7d', 'id': u'6dd637dd-684b-45e1-b343-488c70f1acef', 'instance_id': None, 'mgmt_url': None, 'placement_attr': {'vim_name': u'localdev'}, 'attributes': {}, 'template_id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'vnftest22'}}} mgmt_call /usr/local/lib/python2.7/dist-packages/tacker/vm/mgmt_drivers/noop.py:44
2017-03-06 20:03:20.863 6417 ERROR tacker.api.v1.resource [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] create failed
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource Traceback (most recent call last):
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/api/v1/resource.py", line 89, in resource
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource result = method(request=request, **args)
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/api/v1/base.py", line 395, in create
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource obj = obj_creator(request.context, **kwargs)
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/vm/plugin.py", line 403, in create_vnf
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource vnf_dict = self.create_device(context, vnf)
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/vm/plugin.py", line 274, in create_device
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource device_dict = self._create_device(context, device_info, vim_auth)
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/vm/plugin.py", line 262, in _create_device
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource self.delete_device(context, device_id)
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/openstack/common/excutils.py", line 82, in __exit__
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource six.reraise(self.type_, self.value, self.tb)
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/vm/plugin.py", line 259, in _create_device
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource context=context, device=device_dict, auth_attr=vim_auth)
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/common/driver_manager.py", line 74, in invoke
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource return getattr(driver, method_name)(**kwargs)
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/common/log.py", line 33, in wrapper
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource return method(*args, **kwargs)
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/vm/infra_drivers/heat/heat.py", line 411, in create
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource stack = heatclient_.create(fields)
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/vm/infra_drivers/heat/heat.py", line 562, in create
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource raise vnfm.HeatClientException(msg=value)
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource HeatClientException: ERROR: Property error: : resources.vdu1.properties.image: : "Cirros" does not validate glance.image (constraint not found)
2017-03-06 20:03:20.863 6417 TRACE tacker.api.v1.resource
2017-03-06 20:03:20.869 6417 INFO tacker.wsgi [req-dfe0c4d8-fa38-4912-984f-60648f69180b None] 10.139.4.100 - - [06/Mar/2017 20:03:20] "POST /v1.0/vnfs.json HTTP/1.1" 500 434 3.410411

2017-03-06 22:06:55.673 9057 INFO tacker.common.config [-] Logging enabled!
2017-03-06 22:06:55.682 9057 DEBUG tacker.service [-] ******************************************************************************** log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2503
2017-03-06 22:06:55.682 9057 DEBUG tacker.service [-] Configuration options gathered from: log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2504
2017-03-06 22:06:55.682 9057 DEBUG tacker.service [-] command line args: ['--config-file', '/usr/local/etc/tacker/tacker.conf', '--log-file', '/var/log/tacker/tacker.log'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2505
2017-03-06 22:06:55.683 9057 DEBUG tacker.service [-] config files: ['/usr/local/etc/tacker/tacker.conf'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2507
2017-03-06 22:06:55.683 9057 DEBUG tacker.service [-] ================================================================================ log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2508
2017-03-06 22:06:55.683 9057 DEBUG tacker.service [-] allow_bulk = True log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.683 9057 DEBUG tacker.service [-] allow_pagination = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.683 9057 DEBUG tacker.service [-] allow_sorting = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.684 9057 DEBUG tacker.service [-] api_extensions_path = log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.684 9057 DEBUG tacker.service [-] api_paste_config = api-paste.ini log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.684 9057 DEBUG tacker.service [-] api_workers = 0 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.684 9057 DEBUG tacker.service [-] auth_strategy = keystone log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.685 9057 DEBUG tacker.service [-] backdoor_port = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.685 9057 DEBUG tacker.service [-] backlog = 4096 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.685 9057 DEBUG tacker.service [-] bind_host = 10.139.4.100 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.685 9057 DEBUG tacker.service [-] bind_port = 9890 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.685 9057 DEBUG tacker.service [-] config_dir = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.685 9057 DEBUG tacker.service [-] config_file = ['/usr/local/etc/tacker/tacker.conf'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.686 9057 DEBUG tacker.service [-] control_exchange = tacker log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.686 9057 DEBUG tacker.service [-] debug = True log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.686 9057 DEBUG tacker.service [-] default_log_levels = ['amqp=WARN', 'amqplib=WARN', 'boto=WARN', 'qpid=WARN', 'sqlalchemy=WARN', 'suds=INFO', 'iso8601=WARN'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.686 9057 DEBUG tacker.service [-] disable_process_locking = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.686 9057 DEBUG tacker.service [-] fatal_deprecations = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.687 9057 DEBUG tacker.service [-] host = controler log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.687 9057 DEBUG tacker.service [-] instance_format = [instance: %(uuid)s] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.687 9057 DEBUG tacker.service [-] instance_uuid_format = [instance: %(uuid)s] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.687 9057 DEBUG tacker.service [-] lock_path = /var/lib/tacker/lock log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.687 9057 DEBUG tacker.service [-] log_config_append = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.688 9057 DEBUG tacker.service [-] log_date_format = %Y-%m-%d %H:%M:%S log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.688 9057 DEBUG tacker.service [-] log_dir = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.688 9057 DEBUG tacker.service [-] log_file = /var/log/tacker/tacker.log log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.688 9057 DEBUG tacker.service [-] log_format = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.688 9057 DEBUG tacker.service [-] logging_context_format_string = %(asctime)s.%(msecs)03d %(process)d %(levelname)s %(name)s [%(request_id)s %(user_identity)s] %(instance)s%(message)s log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.688 9057 DEBUG tacker.service [-] logging_debug_format_suffix = %(funcName)s %(pathname)s:%(lineno)d log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.689 9057 DEBUG tacker.service [-] logging_default_format_string = %(asctime)s.%(msecs)03d %(process)d %(levelname)s %(name)s [-] %(instance)s%(message)s log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.689 9057 DEBUG tacker.service [-] logging_exception_prefix = %(asctime)s.%(msecs)03d %(process)d TRACE %(name)s %(instance)s log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.689 9057 DEBUG tacker.service [-] max_header_line = 16384 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.689 9057 DEBUG tacker.service [-] nova_admin_auth_url = http://localhost:5000/v2.0 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.689 9057 DEBUG tacker.service [-] nova_admin_password = **** log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.689 9057 DEBUG tacker.service [-] nova_admin_tenant_id = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.690 9057 DEBUG tacker.service [-] nova_admin_username = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.690 9057 DEBUG tacker.service [-] nova_api_insecure = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.690 9057 DEBUG tacker.service [-] nova_ca_certificates_file = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.690 9057 DEBUG tacker.service [-] nova_region_name = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.690 9057 DEBUG tacker.service [-] nova_url = http://127.0.0.1:8774/v2 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.691 9057 DEBUG tacker.service [-] pagination_max_limit = -1 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.691 9057 DEBUG tacker.service [-] periodic_fuzzy_delay = 5 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.691 9057 DEBUG tacker.service [-] periodic_interval = 40 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.692 9057 DEBUG tacker.service [-] policy_file = /usr/local/etc/tacker/policy.json log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.692 9057 DEBUG tacker.service [-] publish_errors = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.693 9057 DEBUG tacker.service [-] retry_until_window = 30 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.693 9057 DEBUG tacker.service [-] rpc_backend = rabbit log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.693 9057 DEBUG tacker.service [-] service_plugins = ['vnfm', 'nfvo'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.694 9057 DEBUG tacker.service [-] ssl_ca_file = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.694 9057 DEBUG tacker.service [-] ssl_cert_file = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.694 9057 DEBUG tacker.service [-] ssl_key_file = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.695 9057 DEBUG tacker.service [-] state_path = /var/lib/tacker log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.695 9057 DEBUG tacker.service [-] syslog_log_facility = LOG_USER log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.695 9057 DEBUG tacker.service [-] tcp_keepidle = 600 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.696 9057 DEBUG tacker.service [-] transport_url = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.696 9057 DEBUG tacker.service [-] use_ssl = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.696 9057 DEBUG tacker.service [-] use_stderr = True log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.697 9057 DEBUG tacker.service [-] use_syslog = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.697 9057 DEBUG tacker.service [-] verbose = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2517
2017-03-06 22:06:55.697 9057 DEBUG tacker.service [-] oslo_messaging_notifications.driver = ['tacker.openstack.common.notifier.rpc_notifier'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.698 9057 DEBUG tacker.service [-] oslo_messaging_notifications.topics = ['notifications'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.698 9057 DEBUG tacker.service [-] oslo_messaging_notifications.transport_url = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.699 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.amqp_auto_delete = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.699 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.amqp_durable_queues = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.699 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.fake_rabbit = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.699 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.heartbeat_rate = 2 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.700 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.heartbeat_timeout_threshold = 60 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.700 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.kombu_compression = None log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.700 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.kombu_failover_strategy = round-robin log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.700 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.kombu_missing_consumer_retry_timeout = 60 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.700 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.kombu_reconnect_delay = 1.0 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.701 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.kombu_ssl_ca_certs = log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.701 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.kombu_ssl_certfile = log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.701 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.kombu_ssl_keyfile = log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.701 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.kombu_ssl_version = log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.701 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.rabbit_ha_queues = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.702 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.rabbit_host = localhost log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.702 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.rabbit_hosts = ['localhost:5672'] log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.702 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.rabbit_interval_max = 30 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.702 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.rabbit_login_method = AMQPLAIN log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.703 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.rabbit_max_retries = 0 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.703 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.rabbit_password = **** log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.703 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.rabbit_port = 5672 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.703 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.rabbit_qos_prefetch_count = 0 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.703 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.rabbit_retry_backoff = 2 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.704 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.rabbit_retry_interval = 1 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.704 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.rabbit_transient_queues_ttl = 1800 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.704 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.rabbit_use_ssl = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.704 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.rabbit_userid = guest log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.704 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.rabbit_virtual_host = / log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.705 9057 DEBUG tacker.service [-] oslo_messaging_rabbit.rpc_conn_pool_size = 30 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.705 9057 DEBUG tacker.service [-] oslo_concurrency.disable_process_locking = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.705 9057 WARNING oslo_config.cfg [-] Option "lock_path" from group "DEFAULT" is deprecated. Use option "lock_path" from group "oslo_concurrency".
2017-03-06 22:06:55.705 9057 DEBUG tacker.service [-] oslo_concurrency.lock_path = /var/lib/tacker/lock log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.705 9057 DEBUG tacker.service [-] database.backend = sqlalchemy log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.706 9057 DEBUG tacker.service [-] database.connection = **** log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.706 9057 DEBUG tacker.service [-] database.connection_debug = 0 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.706 9057 DEBUG tacker.service [-] database.connection_trace = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.706 9057 DEBUG tacker.service [-] database.db_inc_retry_interval = True log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.707 9057 DEBUG tacker.service [-] database.db_max_retries = 20 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.707 9057 DEBUG tacker.service [-] database.db_max_retry_interval = 10 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.707 9057 DEBUG tacker.service [-] database.db_retry_interval = 1 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.707 9057 DEBUG tacker.service [-] database.idle_timeout = 3600 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.707 9057 DEBUG tacker.service [-] database.max_overflow = 20 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.708 9057 DEBUG tacker.service [-] database.max_pool_size = 10 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.708 9057 DEBUG tacker.service [-] database.max_retries = 10 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.708 9057 DEBUG tacker.service [-] database.min_pool_size = 1 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.708 9057 DEBUG tacker.service [-] database.mysql_sql_mode = TRADITIONAL log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.709 9057 DEBUG tacker.service [-] database.pool_timeout = 10 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.709 9057 DEBUG tacker.service [-] database.retry_interval = 10 log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.709 9057 DEBUG tacker.service [-] database.sqlite_db = log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.709 9057 DEBUG tacker.service [-] database.sqlite_synchronous = True log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.709 9057 DEBUG tacker.service [-] database.use_db_reconnect = False log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2525
2017-03-06 22:06:55.710 9057 DEBUG tacker.service [-] ******************************************************************************** log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2527
2017-03-06 22:06:55.710 9057 INFO tacker.common.config [-] Config paste file: /usr/local/etc/tacker/api-paste.ini
2017-03-06 22:06:56.099 9057 INFO tacker.api.extensions [-] Initializing extension manager.
2017-03-06 22:06:56.100 9057 DEBUG tacker.api.extensions [-] Loading extension file: __init__.py _load_all_extensions_from_path /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:552
2017-03-06 22:06:56.100 9057 DEBUG tacker.api.extensions [-] Loading extension file: __init__.pyc _load_all_extensions_from_path /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:552
2017-03-06 22:06:56.101 9057 DEBUG tacker.api.extensions [-] Loading extension file: nfvo.py _load_all_extensions_from_path /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:552
2017-03-06 22:06:56.122 9057 DEBUG tacker.api.extensions [-] Ext name: NFVO _check_extension /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:519
2017-03-06 22:06:56.123 9057 DEBUG tacker.api.extensions [-] Ext alias: NFV Orchestrator _check_extension /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:520
2017-03-06 22:06:56.123 9057 DEBUG tacker.api.extensions [-] Ext description: Extension for NFV Orchestrator _check_extension /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:521
2017-03-06 22:06:56.124 9057 DEBUG tacker.api.extensions [-] Ext namespace: http://wiki.openstack.org/Tacker _check_extension /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:522
2017-03-06 22:06:56.124 9057 DEBUG tacker.api.extensions [-] Ext updated: 2015-12-21T10:00:00-00:00 _check_extension /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:523
2017-03-06 22:06:56.125 9057 INFO tacker.api.extensions [-] Loaded extension: NFV Orchestrator
2017-03-06 22:06:56.125 9057 DEBUG tacker.api.extensions [-] Loading extension file: nfvo.pyc _load_all_extensions_from_path /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:552
2017-03-06 22:06:56.125 9057 DEBUG tacker.api.extensions [-] Loading extension file: vnfm.py _load_all_extensions_from_path /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:552
2017-03-06 22:06:56.129 9057 DEBUG tacker.api.extensions [-] Ext name: VNFM _check_extension /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:519
2017-03-06 22:06:56.129 9057 DEBUG tacker.api.extensions [-] Ext alias: VNF Manager _check_extension /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:520
2017-03-06 22:06:56.129 9057 DEBUG tacker.api.extensions [-] Ext description: Extension for VNF Manager _check_extension /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:521
2017-03-06 22:06:56.130 9057 DEBUG tacker.api.extensions [-] Ext namespace: http://wiki.openstack.org/Tacker _check_extension /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:522
2017-03-06 22:06:56.130 9057 DEBUG tacker.api.extensions [-] Ext updated: 2013-11-19T10:00:00-00:00 _check_extension /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:523
2017-03-06 22:06:56.130 9057 INFO tacker.api.extensions [-] Loaded extension: VNF Manager
2017-03-06 22:06:56.131 9057 DEBUG tacker.api.extensions [-] Loading extension file: vnfm.pyc _load_all_extensions_from_path /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:552
2017-03-06 22:06:56.131 9057 DEBUG routes.middleware [-] Initialized with method overriding = True, and path info altering = True __init__ /usr/lib/python2.7/dist-packages/routes/middleware.py:42
2017-03-06 22:06:56.131 9057 DEBUG tacker.openstack.common.lockutils [-] Got semaphore "manager" lock /usr/local/lib/python2.7/dist-packages/tacker/openstack/common/lockutils.py:168
2017-03-06 22:06:56.132 9057 DEBUG tacker.openstack.common.lockutils [-] Got semaphore / lock "_create_instance" inner /usr/local/lib/python2.7/dist-packages/tacker/openstack/common/lockutils.py:248
2017-03-06 22:06:56.132 9057 DEBUG tacker.manager [-] Loading service plugins: ['vnfm', 'nfvo'] _load_service_plugins /usr/local/lib/python2.7/dist-packages/tacker/manager.py:133
2017-03-06 22:06:56.133 9057 INFO tacker.manager [-] Loading Plugin: vnfm
2017-03-06 22:06:56.133 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('dummy = tacker.tests.unit.dummy_plugin:DummyServicePlugin') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.134 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('nfvo = tacker.nfvo.nfvo_plugin:NfvoPlugin') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.134 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('vnfm = tacker.vm.plugin:VNFMPlugin') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.240 9057 INFO tosca.model [-] nfv
2017-03-06 22:06:56.241 9057 INFO tosca.model [-] tosca_simple_profile_for_nfv_1_0_0.py
2017-03-06 22:06:56.294 9057 INFO tosca.model [-] nfv
2017-03-06 22:06:56.295 9057 INFO tosca.model [-] tosca_simple_profile_for_nfv_1_0_0.py
2017-03-06 22:06:56.351 9057 DEBUG tacker.openstack.common.db.sqlalchemy.session [-] MySQL server mode set to STRICT_TRANS_TABLES,STRICT_ALL_TABLES,NO_ZERO_IN_DATE,NO_ZERO_DATE,ERROR_FOR_DIVISION_BY_ZERO,TRADITIONAL,NO_AUTO_CREATE_USER,NO_ENGINE_SUBSTITUTION _mysql_check_effective_sql_mode /usr/local/lib/python2.7/dist-packages/tacker/openstack/common/db/sqlalchemy/session.py:562
2017-03-06 22:06:56.359 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('noop = tacker.vm.mgmt_drivers.noop:DeviceMgmtNoop') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.376 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('openwrt = tacker.vm.mgmt_drivers.openwrt.openwrt:DeviceMgmtOpenWRT') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.390 9057 INFO tacker.common.driver_manager [-] Registered drivers from tacker.tacker.mgmt.drivers: ['noop', 'openwrt']
2017-03-06 22:06:56.390 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('heat = tacker.vm.infra_drivers.heat.heat:DeviceHeat') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.391 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('noop = tacker.vm.infra_drivers.noop:DeviceNoop') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.392 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('nova = tacker.vm.infra_drivers.nova.nova:DeviceNova') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.395 9057 INFO tacker.common.driver_manager [-] Registered drivers from tacker.tacker.device.drivers: ['heat', 'noop', 'nova']
2017-03-06 22:06:56.396 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('http_ping = tacker.vm.monitor_drivers.http_ping.http_ping:VNFMonitorHTTPPing') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.400 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('ping = tacker.vm.monitor_drivers.ping.ping:VNFMonitorPing') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.401 9057 INFO tacker.common.driver_manager [-] Registered drivers from tacker.tacker.monitor.drivers: ['http_ping', 'ping']
2017-03-06 22:06:56.402 9057 DEBUG tacker.vm.monitor [-] Spawning VNF monitor thread __init__ /usr/local/lib/python2.7/dist-packages/tacker/vm/monitor.py:77
2017-03-06 22:06:56.402 9057 DEBUG tacker.manager [-] Successfully loaded VNFM plugin. Description: Tacker VNF Manager plugin _load_service_plugins /usr/local/lib/python2.7/dist-packages/tacker/manager.py:159
2017-03-06 22:06:56.403 9057 INFO tacker.manager [-] Loading Plugin: nfvo
2017-03-06 22:06:56.403 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('dummy = tacker.tests.unit.dummy_plugin:DummyServicePlugin') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.403 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('nfvo = tacker.nfvo.nfvo_plugin:NfvoPlugin') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.412 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('vnfm = tacker.vm.plugin:VNFMPlugin') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.420 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('openstack = tacker.nfvo.drivers.vim.openstack_driver:OpenStack_Driver') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.424 9057 INFO tacker.common.driver_manager [-] Registered drivers from tacker.nfvo.vim.drivers: ['openstack']
2017-03-06 22:06:56.425 9057 DEBUG tacker.manager [-] Successfully loaded NFVO plugin. Description: Tacker NFV Orchestrator plugin _load_service_plugins /usr/local/lib/python2.7/dist-packages/tacker/manager.py:159
2017-03-06 22:06:56.425 9057 DEBUG tacker.openstack.common.lockutils [-] Semaphore / lock released "_create_instance" inner /usr/local/lib/python2.7/dist-packages/tacker/openstack/common/lockutils.py:252
2017-03-06 22:06:56.426 9057 DEBUG tacker.api.extensions [-] Extended resource: extensions __init__ /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:282
2017-03-06 22:06:56.427 9057 DEBUG tacker.api.extensions [-] Extended resource: vnfds __init__ /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:282
2017-03-06 22:06:56.428 9057 DEBUG tacker.api.extensions [-] Extended resource: vnfs __init__ /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:282
2017-03-06 22:06:56.429 9057 DEBUG tacker.api.extensions [-] Extended resource: vims __init__ /usr/local/lib/python2.7/dist-packages/tacker/api/extensions.py:282
2017-03-06 22:06:56.430 9057 DEBUG routes.middleware [-] Initialized with method overriding = True, and path info altering = True __init__ /usr/lib/python2.7/dist-packages/routes/middleware.py:42
2017-03-06 22:06:56.430 9057 INFO keystonemiddleware.auth_token [-] Starting Keystone auth_token middleware
2017-03-06 22:06:56.432 9057 WARNING oslo_config.cfg [-] Option "auth_plugin" from group "keystone_authtoken" is deprecated. Use option "auth_type" from group "keystone_authtoken".
2017-03-06 22:06:56.432 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('v2token = keystoneauth1.loading._plugins.identity.v2:Token') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.433 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('v3oauth1 = keystoneauth1.extras.oauth1._loading:V3OAuth1') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.433 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('admin_token = keystoneauth1.loading._plugins.admin_token:AdminToken') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.433 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('v3oidcauthcode = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAuthorizationCode') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.433 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('v2password = keystoneauth1.loading._plugins.identity.v2:Password') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.433 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('v3samlpassword = keystoneauth1.extras._saml2._loading:Saml2Password') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.433 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('v3password = keystoneauth1.loading._plugins.identity.v3:Password') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.433 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('v3oidcaccesstoken = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectAccessToken') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.433 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('v3oidcpassword = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectPassword') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.434 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('v3kerberos = keystoneauth1.extras.kerberos._loading:Kerberos') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.434 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('token = keystoneauth1.loading._plugins.identity.generic:Token') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.434 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('v3oidcclientcredentials = keystoneauth1.loading._plugins.identity.v3:OpenIDConnectClientCredentials') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.434 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('v3tokenlessauth = keystoneauth1.loading._plugins.identity.v3:TokenlessAuth') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.434 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('v3token = keystoneauth1.loading._plugins.identity.v3:Token') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.434 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('v3totp = keystoneauth1.loading._plugins.identity.v3:TOTP') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.434 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('password = keystoneauth1.loading._plugins.identity.generic:Password') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.435 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('v3fedkerb = keystoneauth1.extras.kerberos._loading:MappedKerberos') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.435 9057 DEBUG stevedore.extension [-] found extension EntryPoint.parse('password-ceilometer-legacy = ceilometer.keystone_client:LegacyCeilometerKeystoneLoader') _load_plugins /usr/local/lib/python2.7/dist-packages/stevedore/extension.py:180
2017-03-06 22:06:56.436 9057 INFO keystonemiddleware.auth_token [-] Using /var/cache/tacker as cache directory for signing certificate
2017-03-06 22:07:10.365 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 39358)

2017-03-06 22:07:10.367 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 22:07:10.369 6417 DEBUG keystoneauth.identity.v3.base [-] Making authentication request to http://controler:35357/v3/auth/tokens get_auth_ref /usr/local/lib/python2.7/dist-packages/keystoneauth1/identity/v3/base.py:165
2017-03-06 22:07:10.371 6417 DEBUG requests.packages.urllib3.connectionpool [-] Resetting dropped connection: controler _get_conn /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:242
2017-03-06 22:07:10.511 6417 DEBUG requests.packages.urllib3.connectionpool [-] http://controler:35357 "POST /v3/auth/tokens HTTP/1.1" 201 5154 _make_request /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:395
2017-03-06 22:07:10.513 6417 DEBUG keystoneauth.identity.v3.base [-] {"token": {"methods": ["password"], "roles": [{"id": "71a4e83e07624c508679db8ee4ecc275", "name": "admin"}], "expires_at": "2017-03-06T17:37:10.508186Z", "project": {"domain": {"id": "44afe88f79ca491ca47748539ac5796b", "name": "default"}, "id": "052de98620b64c10be3e2095584708a2", "name": "service"}, "catalog": [{"endpoints": [{"url": "http://controler:8777", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "06a2ebac1fb44e2a80a7eb0ea853743a"}, {"url": "http://controler:8777", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "1c83ab02d0544d1d9c97f8a9a763c2c6"}, {"url": "http://controler:8777", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "475689f2014d4d9c8831d574061c9199"}], "type": "metering", "id": "2616a8788a0140cb87c05f8ba315f5d5", "name": "ceilometer"}, {"endpoints": [{"url": "http://10.139.4.100:9890", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "3ede3c79370d4615ae575d0ae3e793ef"}, {"url": "http://10.139.4.100:9890", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "7ff22332505546d587a9ab1783a2ce88"}, {"url": "http://10.139.4.100:9890/", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "dfa0aaa1753f4504ad849dbf1a15b504"}], "type": "nfv-orchestration", "id": "29413625ad8d4f54a359ad8004ca4fd1", "name": "tacker"}, {"endpoints": [{"url": "http://controler:9292", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "189c9ccba64b447fa49fc70df1892358"}, {"url": "http://controler:9292", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "2b1ce4b2d48c4e3cb0c747adfeb2909a"}, {"url": "http://controler:9292", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "c501882747cd4c2380eaaed27621d5e1"}], "type": "image", "id": "8906e6942827476baad1b160d49ff75a", "name": "glance"}, {"endpoints": [{"url": "http://controler:8004/v1/052de98620b64c10be3e2095584708a2", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "35058257e2374ec19cc0c6c9ce65163c"}, {"url": "http://controler:8004/v1/052de98620b64c10be3e2095584708a2", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "afa8753d36124bccaf3ef74d6d68648b"}, {"url": "http://controler:8004/v1/052de98620b64c10be3e2095584708a2", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "e7d5915178a74137841660b45f06672e"}], "type": "orchestration", "id": "aebfea33f4b74230be0e96104e0cde15", "name": "heat"}, {"endpoints": [{"url": "http://controler:9696", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "3ed08201ee4a44e8b17426a065341cb6"}, {"url": "http://controler:9696", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "3f3e892055954cce85937d999ec00321"}, {"url": "http://controler:9696", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "edeeeab56c014b2fb156f094426ae002"}], "type": "network", "id": "c08d1790831e4a6eadfe934a37da948e", "name": "neutron"}, {"endpoints": [{"url": "http://controler:35357/v2.0", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "1d314c19d472472c887cdfb533b68e7c"}, {"url": "http://controler:5000/v2.0", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "a77a5acbadbc4588b38e4ee733d8449f"}, {"url": "http://controler:5000/v2.0", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "fd1ed4987c784761a4c2e35f01f2fab0"}], "type": "identity", "id": "ca417bc0cb7645d98bbf182623cc1b8f", "name": "keystone"}, {"endpoints": [{"url": "http://controler:8774/v2.1/052de98620b64c10be3e2095584708a2", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "091ccc1cf7fb4d709f116d85efa5ce2c"}, {"url": "http://controler:8774/v2.1/052de98620b64c10be3e2095584708a2", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "6d5090da2951408aadfbe8e8a0db5f13"}, {"url": "http://controler:8774/v2.1/052de98620b64c10be3e2095584708a2", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "85cec26f36a54f25b5c98477b13b0d0d"}], "type": "compute", "id": "d636f8bd6ee141d3a9cafcfa6a73957a", "name": "nova"}, {"endpoints": [{"url": "http://controler:8000/v1", "interface": "public", "region": "RegionOne", "region_id": "RegionOne", "id": "3406ab08617a47e7846faab161d798b8"}, {"url": "http://controler:8000/v1", "interface": "internal", "region": "RegionOne", "region_id": "RegionOne", "id": "881f1809c0ce49e08045fa0798fde99e"}, {"url": "http://controler:8000/v1", "interface": "admin", "region": "RegionOne", "region_id": "RegionOne", "id": "bc5168a483c64fc498a465f40cda5c4e"}], "type": "cloudformation", "id": "fa06c529d38e49a0a5bfbd53c34c4a85", "name": "heat-cfn"}], "user": {"domain": {"id": "44afe88f79ca491ca47748539ac5796b", "name": "default"}, "id": "4aeabb5062004ceeaf4521f8a14f4bb2", "name": "tacker"}, "audit_ids": ["s3mfn6jyT9yY6PGBi9Hy1g"], "issued_at": "2017-03-06T16:37:10.000000Z"}} get_auth_ref /usr/local/lib/python2.7/dist-packages/keystoneauth1/identity/v3/base.py:170
2017-03-06 22:07:10.514 6417 DEBUG keystoneauth.session [-] REQ: curl -g -i --cacert "/opt/stack/data/ca-bundle.pem" -X GET http://controler:35357/v3/auth/tokens -H "X-Subject-Token: {SHA1}9186a16dfdf30b5f80305e7a1a799e46e9259e59" -H "User-Agent: python-keystoneclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}0e84307117b2236029d31912d1be2401b48307eb" _http_log_request /usr/local/lib/python2.7/dist-packages/keystoneauth1/session.py:347
2017-03-06 22:07:10.747 6417 DEBUG requests.packages.urllib3.connectionpool [-] http://controler:35357 "GET /v3/auth/tokens HTTP/1.1" 200 5246 _make_request /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:395
2017-03-06 22:07:10.748 6417 DEBUG keystoneauth.session [-] RESP: [200] Date: Mon, 06 Mar 2017 16:37:10 GMT Server: Apache/2.4.7 (Ubuntu) X-Subject-Token: {SHA1}9186a16dfdf30b5f80305e7a1a799e46e9259e59 Vary: X-Auth-Token X-Distribution: Ubuntu x-openstack-request-id: req-02237d30-9991-489a-8d7f-8168aeed6f30 Content-Length: 5246 Keep-Alive: timeout=5, max=99 Connection: Keep-Alive Content-Type: application/json
RESP BODY: {"token": {"methods": ["token", "password"], "roles": [{"id": "71a4e83e07624c508679db8ee4ecc275", "name": "admin"}, {"id": "10e802b95f3f4b45a7384fea17438681", "name": "user"}], "expires_at": "2017-03-06T17:06:06.930158Z", "project": {"domain": {"id": "44afe88f79ca491ca47748539ac5796b", "name": "default"}, "id": "1dfdb8d3adc64559a2870bb086c441b6", "name": "admin"}, "catalog": "<removed>", "user": {"domain": {"id": "44afe88f79ca491ca47748539ac5796b", "name": "default"}, "id": "9fe0f2888cc343fb84e75fcacbe6c53d", "name": "admin"}, "audit_ids": ["F6HcGPDyT5q4gXmV_mNPxw", "KUuIFUZUTNyxZ-mHAJ5SsA"], "issued_at": "2017-03-06T16:06:07.000000Z"}}
 _http_log_response /usr/local/lib/python2.7/dist-packages/keystoneauth1/session.py:395
2017-03-06 22:07:10.748 6417 DEBUG keystoneauth.session [-] GET call to identity for http://controler:35357/v3/auth/tokens used request id req-02237d30-9991-489a-8d7f-8168aeed6f30 request /usr/local/lib/python2.7/dist-packages/keystoneauth1/session.py:640
2017-03-06 22:07:10.749 6417 DEBUG keystonemiddleware.auth_token [-] Storing token in cache store /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/_cache.py:149
2017-03-06 22:07:10.750 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 22:07:10.751 6417 DEBUG routes.middleware [-] Matched GET /vnfds.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 22:07:10.751 6417 DEBUG routes.middleware [-] Route path: '/vnfds.:(format)', defaults: {'action': u'index', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 22:07:10.751 6417 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>, 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 22:07:10.767 6417 INFO tacker.wsgi [req-f1bad08e-2d2c-4836-b602-e1b96a5b1177 None] 10.139.4.100 - - [06/Mar/2017 22:07:10] "GET /v1.0/vnfds.json HTTP/1.1" 200 988 0.400064

2017-03-06 22:07:13.827 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 39368)

2017-03-06 22:07:13.828 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 22:07:13.829 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 22:07:13.830 6417 DEBUG routes.middleware [-] Matched GET /vnfds/a4e93c57-e536-4c3a-9d84-d00ea4ff2777.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 22:07:13.831 6417 DEBUG routes.middleware [-] Route path: '/vnfds/:(id).:(format)', defaults: {'action': u'show', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 22:07:13.831 6417 DEBUG routes.middleware [-] Match dict: {'action': u'show', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>, 'id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 22:07:13.838 6417 INFO tacker.wsgi [req-d4a0440a-1031-4444-95ad-19a505c04663 None] 10.139.4.100 - - [06/Mar/2017 22:07:13] "GET /v1.0/vnfds/a4e93c57-e536-4c3a-9d84-d00ea4ff2777.json HTTP/1.1" 200 985 0.010326

2017-03-06 22:07:22.320 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 39376)

2017-03-06 22:07:22.323 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 22:07:22.324 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 22:07:22.326 6417 DEBUG routes.middleware [-] Matched GET /vnfs.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 22:07:22.326 6417 DEBUG routes.middleware [-] Route path: '/vnfs.:(format)', defaults: {'action': u'index', 'controller': <wsgify at 140247309049232 wrapping <function resource at 0x7f8ddf097230>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 22:07:22.326 6417 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 140247309049232 wrapping <function resource at 0x7f8ddf097230>>, 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 22:07:22.330 6417 INFO tacker.wsgi [req-b007d814-8086-4606-b15e-2f79889059d0 None] 10.139.4.100 - - [06/Mar/2017 22:07:22] "GET /v1.0/vnfs.json HTTP/1.1" 200 225 0.007746

2017-03-06 22:07:26.459 9057 ERROR tacker.service [-] Unrecoverable error: please check log for details.
2017-03-06 22:07:26.459 9057 TRACE tacker.service Traceback (most recent call last):
2017-03-06 22:07:26.459 9057 TRACE tacker.service File "/usr/local/lib/python2.7/dist-packages/tacker/service.py", line 88, in serve_wsgi
2017-03-06 22:07:26.459 9057 TRACE tacker.service service.start()
2017-03-06 22:07:26.459 9057 TRACE tacker.service File "/usr/local/lib/python2.7/dist-packages/tacker/service.py", line 59, in start
2017-03-06 22:07:26.459 9057 TRACE tacker.service self.wsgi_app = _run_wsgi(self.app_name)
2017-03-06 22:07:26.459 9057 TRACE tacker.service File "/usr/local/lib/python2.7/dist-packages/tacker/service.py", line 104, in _run_wsgi
2017-03-06 22:07:26.459 9057 TRACE tacker.service workers=cfg.CONF.api_workers)
2017-03-06 22:07:26.459 9057 TRACE tacker.service File "/usr/local/lib/python2.7/dist-packages/tacker/wsgi.py", line 211, in start
2017-03-06 22:07:26.459 9057 TRACE tacker.service backlog=backlog)
2017-03-06 22:07:26.459 9057 TRACE tacker.service File "/usr/local/lib/python2.7/dist-packages/tacker/wsgi.py", line 190, in _get_socket
2017-03-06 22:07:26.459 9057 TRACE tacker.service 'time': CONF.retry_until_window})
2017-03-06 22:07:26.459 9057 TRACE tacker.service RuntimeError: Could not bind to 10.139.4.100:9890 after trying for 30 seconds
2017-03-06 22:07:26.459 9057 TRACE tacker.service
2017-03-06 22:07:27.392 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 39384)

2017-03-06 22:07:27.393 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 22:07:27.395 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 22:07:27.395 6417 DEBUG routes.middleware [-] Matched GET /vnfds.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 22:07:27.395 6417 DEBUG routes.middleware [-] Route path: '/vnfds.:(format)', defaults: {'action': u'index', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 22:07:27.396 6417 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>, 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 22:07:27.402 6417 INFO tacker.wsgi [req-04a8abd1-18e2-4a1b-b086-449b76b4b72b None] 10.139.4.100 - - [06/Mar/2017 22:07:27] "GET /v1.0/vnfds.json HTTP/1.1" 200 988 0.009323

2017-03-06 22:07:27.406 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 39385)

2017-03-06 22:07:27.407 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 22:07:27.408 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 22:07:27.408 6417 DEBUG routes.middleware [-] Matched GET /vims.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 22:07:27.409 6417 DEBUG routes.middleware [-] Route path: '/vims.:(format)', defaults: {'action': u'index', 'controller': <wsgify at 140247309049744 wrapping <function resource at 0x7f8ddf097488>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 22:07:27.409 6417 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 140247309049744 wrapping <function resource at 0x7f8ddf097488>>, 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 22:07:27.414 6417 INFO tacker.wsgi [req-d609fe1d-dd23-4274-956b-6332c1b8886e None] 10.139.4.100 - - [06/Mar/2017 22:07:27] "GET /v1.0/vims.json HTTP/1.1" 200 861 0.007003

2017-03-06 22:07:44.121 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 39388)

2017-03-06 22:07:44.122 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 22:07:44.123 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 22:07:44.124 6417 DEBUG routes.middleware [-] Matched GET /vnfds.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 22:07:44.124 6417 DEBUG routes.middleware [-] Route path: '/vnfds.:(format)', defaults: {'action': u'index', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 22:07:44.124 6417 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>, 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 22:07:44.131 6417 INFO tacker.wsgi [req-89d7f4e5-6668-4753-8df7-888279265a5e None] 10.139.4.100 - - [06/Mar/2017 22:07:44] "GET /v1.0/vnfds.json HTTP/1.1" 200 988 0.009362

2017-03-06 22:07:44.135 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 39389)

2017-03-06 22:07:44.136 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 22:07:44.137 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 22:07:44.138 6417 DEBUG routes.middleware [-] Matched GET /vims.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 22:07:44.138 6417 DEBUG routes.middleware [-] Route path: '/vims.:(format)', defaults: {'action': u'index', 'controller': <wsgify at 140247309049744 wrapping <function resource at 0x7f8ddf097488>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 22:07:44.138 6417 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 140247309049744 wrapping <function resource at 0x7f8ddf097488>>, 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 22:07:44.144 6417 INFO tacker.wsgi [req-01c2cc73-ac83-4040-b0b3-3e3780d2c4a9 None] 10.139.4.100 - - [06/Mar/2017 22:07:44] "GET /v1.0/vims.json HTTP/1.1" 200 861 0.007570

2017-03-06 22:07:44.148 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 39390)

2017-03-06 22:07:44.149 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 22:07:44.150 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 22:07:44.151 6417 DEBUG routes.middleware [-] Matched POST /vnfs.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 22:07:44.151 6417 DEBUG routes.middleware [-] Route path: '/vnfs.:(format)', defaults: {'action': u'create', 'controller': <wsgify at 140247309049232 wrapping <function resource at 0x7f8ddf097230>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 22:07:44.151 6417 DEBUG routes.middleware [-] Match dict: {'action': u'create', 'controller': <wsgify at 140247309049232 wrapping <function resource at 0x7f8ddf097230>>, 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 22:07:44.152 6417 DEBUG tacker.api.v1.base [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] Request body: {u'vnf': {u'attributes': {}, u'vim_id': u'aed4074f-7df2-424e-87b1-d013aeb50e7d', u'vnfd_id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', u'name': u'firstvnf'}, u'placement_attr': {u'RegionOne': u'RegionOne'}} prepare_request_body /usr/local/lib/python2.7/dist-packages/tacker/api/v1/base.py:509
2017-03-06 22:07:44.157 6417 DEBUG tacker.vm.vim_client [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] VIM info found for vim id aed4074f-7df2-424e-87b1-d013aeb50e7d get_vim /usr/local/lib/python2.7/dist-packages/tacker/vm/vim_client.py:62
2017-03-06 22:07:44.158 6417 DEBUG tacker.vm.vim_client [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] VIM id is aed4074f-7df2-424e-87b1-d013aeb50e7d _build_vim_auth /usr/local/lib/python2.7/dist-packages/tacker/vm/vim_client.py:77
2017-03-06 22:07:44.158 6417 DEBUG tacker.vm.vim_client [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] Attempting to open key file for vim id aed4074f-7df2-424e-87b1-d013aeb50e7d _find_vim_key /usr/local/lib/python2.7/dist-packages/tacker/vm/vim_client.py:101
2017-03-06 22:07:44.160 6417 DEBUG tacker.db.vm.vm_db [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] device {'description': '', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', u'vim_id': u'aed4074f-7df2-424e-87b1-d013aeb50e7d', 'placement_attr': {'vim_name': u'localdev'}, u'attributes': {}, 'template_id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', u'name': u'firstvnf'} _create_device_pre /usr/local/lib/python2.7/dist-packages/tacker/db/vm/vm_db.py:342
2017-03-06 22:07:44.170 6417 DEBUG tacker.db.vm.vm_db [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] device_db <tacker.db.vm.vm_db.Device[object at 7f8ddeb7d7d0] {tenant_id=u'1dfdb8d3adc64559a2870bb086c441b6', id='c75772ad-cfb6-42a3-b17a-4f43cdffb0dd', template_id=u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', name=u'firstvnf', description=u'demo-example', instance_id=None, mgmt_url=None, status='PENDING_CREATE', vim_id=u'aed4074f-7df2-424e-87b1-d013aeb50e7d', placement_attr={'vim_name': u'localdev'}}> _make_device_dict /usr/local/lib/python2.7/dist-packages/tacker/db/vm/vm_db.py:193
2017-03-06 22:07:44.173 6417 DEBUG tacker.db.vm.vm_db [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] device_db attributes [] _make_device_dict /usr/local/lib/python2.7/dist-packages/tacker/db/vm/vm_db.py:194
2017-03-06 22:07:44.177 6417 DEBUG tacker.vm.plugin [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] device_dict {'status': 'PENDING_CREATE', 'device_template': {'service_types': [{'service_type': u'vnfd', 'id': u'ae2cc76c-8b4f-43c7-8471-7dcd15cc95eb'}], 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'mgmt_driver': u'noop', 'infra_driver': u'heat', 'attributes': {u'vnfd': u'template_name: sample-vnfd\ndescription: demo-example\n\nservice_properties:\n Id: sample-vnfd\n vendor: tacker\n version: 1\n\nvdus:\n vdu1:\n id: vdu1\n vm_image: Cirros\n instance_type: m1.tiny\n\n network_interfaces:\n management:\n network: 7918b3b3-6810-435b-970c-7e3e68f6c439\n management: true\n\n placement_policy:\n availability_zone: nova\n\n config:\n param0: key0\n param1: key1\n'}, 'id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'testvnf1'}, 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'vim_id': u'aed4074f-7df2-424e-87b1-d013aeb50e7d', 'id': 'c75772ad-cfb6-42a3-b17a-4f43cdffb0dd', 'instance_id': None, 'mgmt_url': None, 'placement_attr': {'vim_name': u'localdev'}, 'attributes': {}, 'template_id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'firstvnf'} _create_device /usr/local/lib/python2.7/dist-packages/tacker/vm/plugin.py:254
2017-03-06 22:07:44.180 6417 DEBUG tacker.common.log [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] tacker.vm.infra_drivers.heat.heat.DeviceHeat method create called with arguments () {'device': {'status': 'PENDING_CREATE', 'instance_id': None, 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'vim_id': u'aed4074f-7df2-424e-87b1-d013aeb50e7d', 'template_id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'device_template': {'service_types': [{'service_type': u'vnfd', 'id': u'ae2cc76c-8b4f-43c7-8471-7dcd15cc95eb'}], 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'mgmt_driver': u'noop', 'infra_driver': u'heat', 'attributes': {u'vnfd': u'template_name: sample-vnfd\ndescription: demo-example\n\nservice_properties:\n Id: sample-vnfd\n vendor: tacker\n version: 1\n\nvdus:\n vdu1:\n id: vdu1\n vm_image: Cirros\n instance_type: m1.tiny\n\n network_interfaces:\n management:\n network: 7918b3b3-6810-435b-970c-7e3e68f6c439\n management: true\n\n placement_policy:\n availability_zone: nova\n\n config:\n param0: key0\n param1: key1\n'}, 'id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'testvnf1'}, 'mgmt_url': None, 'placement_attr': {'vim_name': u'localdev'}, 'attributes': {}, 'id': 'c75772ad-cfb6-42a3-b17a-4f43cdffb0dd', 'name': u'firstvnf'}, 'auth_attr': {u'username': u'admin', 'password': 'tcs#1234', 'project_name': u'admin', u'user_domain_name': u'default', 'auth_url': u'http://10.139.4.100:5000/v3', 'project_id': None, 'project_domain_name': u'default'}, 'context': <tacker.context.Context object at 0x7f8ddeb5ec90>, 'plugin': <tacker.vm.plugin.VNFMPlugin object at 0x7f8ddf5f3b50>} wrapper /usr/local/lib/python2.7/dist-packages/tacker/common/log.py:32
2017-03-06 22:07:44.187 6417 DEBUG tacker.vm.infra_drivers.heat.heat [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] device {'status': 'PENDING_CREATE', 'device_template': {'service_types': [{'service_type': u'vnfd', 'id': u'ae2cc76c-8b4f-43c7-8471-7dcd15cc95eb'}], 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'mgmt_driver': u'noop', 'infra_driver': u'heat', 'attributes': {u'vnfd': u'template_name: sample-vnfd\ndescription: demo-example\n\nservice_properties:\n Id: sample-vnfd\n vendor: tacker\n version: 1\n\nvdus:\n vdu1:\n id: vdu1\n vm_image: Cirros\n instance_type: m1.tiny\n\n network_interfaces:\n management:\n network: 7918b3b3-6810-435b-970c-7e3e68f6c439\n management: true\n\n placement_policy:\n availability_zone: nova\n\n config:\n param0: key0\n param1: key1\n'}, 'id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'testvnf1'}, 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'vim_id': u'aed4074f-7df2-424e-87b1-d013aeb50e7d', 'id': 'c75772ad-cfb6-42a3-b17a-4f43cdffb0dd', 'instance_id': None, 'mgmt_url': None, 'placement_attr': {'vim_name': u'localdev'}, 'attributes': {}, 'template_id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'firstvnf'} create /usr/local/lib/python2.7/dist-packages/tacker/vm/infra_drivers/heat/heat.py:257
2017-03-06 22:07:44.188 6417 DEBUG keystoneclient.auth.identity.v3.base [-] Making authentication request to http://10.139.4.100:5000/v3/auth/tokens get_auth_ref /usr/lib/python2.7/dist-packages/keystoneclient/auth/identity/v3/base.py:188
2017-03-06 22:07:44.190 6417 DEBUG requests.packages.urllib3.connectionpool [-] Starting new HTTP connection (1): 10.139.4.100 _new_conn /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:207
2017-03-06 22:07:44.324 6417 DEBUG requests.packages.urllib3.connectionpool [-] http://10.139.4.100:5000 "POST /v3/auth/tokens HTTP/1.1" 201 5211 _make_request /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:395
2017-03-06 22:07:44.325 6417 DEBUG keystoneclient.session [-] REQ: curl -g -i -X GET http://controler:8004/v1/1dfdb8d3adc64559a2870bb086c441b6/resource_types/OS%3A%3ANeutron%3A%3APort -H "User-Agent: python-heatclient" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}d1cf5e6df74d60be373f089301fc6810bcb0c651" _http_log_request /usr/lib/python2.7/dist-packages/keystoneclient/session.py:206
2017-03-06 22:07:44.326 6417 DEBUG requests.packages.urllib3.connectionpool [-] Starting new HTTP connection (1): controler _new_conn /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:207
2017-03-06 22:07:44.741 6417 DEBUG requests.packages.urllib3.connectionpool [-] http://controler:8004 "GET /v1/1dfdb8d3adc64559a2870bb086c441b6/resource_types/OS%3A%3ANeutron%3A%3APort HTTP/1.1" 200 6165 _make_request /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:395
2017-03-06 22:07:44.742 6417 DEBUG keystoneclient.session [-] RESP: [200] Content-Type: application/json; charset=UTF-8 Content-Length: 6165 X-Openstack-Request-Id: req-7bf9926d-afb9-4eb1-8287-7730e134311a Date: Mon, 06 Mar 2017 16:37:44 GMT Connection: keep-alive
RESP BODY: {"support_status": {"status": "SUPPORTED", "message": null, "version": null, "previous_status": null}, "attributes": {"status": {"type": "string", "description": "The status of the port."}, "subnets": {"type": "list", "description": "A list of all subnet attributes for the port."}, "name": {"type": "string", "description": "Friendly name of the port."}, "allowed_address_pairs": {"type": "list", "description": "Additional MAC/IP address pairs allowed to pass through a port."}, "admin_state_up": {"type": "string", "description": "The administrative state of this port."}, "network_id": {"type": "string", "description": "Unique identifier for the network owning the port."}, "tenant_id": {"type": "string", "description": "Tenant owning the port."}, "show": {"type": "map", "description": "Detailed information about resource."}, "device_owner": {"type": "string", "description": "Name of the network owning the port."}, "qos_policy_id": {"type": "string", "description": "The QoS policy ID attached to this port."}, "mac_address": {"type": "string", "description": "MAC address of the port."}, "port_security_enabled": {"type": "boolean", "description": "Port security enabled of the port."}, "fixed_ips": {"type": "list", "description": "Fixed IP addresses."}, "security_groups": {"type": "list", "description": "A list of security groups for the port."}, "device_id": {"type": "string", "description": "Unique identifier for the device."}}, "properties": {"replacement_policy": {"description": "Policy on how to respond to a stack-update for this resource. REPLACE_ALWAYS will replace the port regardless of any property changes. AUTO will update the existing port for any changed update-allowed property.", "default": "AUTO", "required": false, "update_allowed": true, "type": "string", "immutable": false, "constraints": [{"allowed_values": ["REPLACE_ALWAYS", "AUTO"]}]}, "name": {"update_allowed": true, "required": false, "type": "string", "description": "A symbolic name for this port.", "immutable": false}, "allowed_address_pairs": {"description": "Additional MAC/IP address pairs allowed to pass through the port.", "required": false, "update_allowed": false, "type": "list", "immutable": false, "schema": {"*": {"update_allowed": false, "required": false, "type": "map", "immutable": false, "schema": {"ip_address": {"description": "IP address to allow through this port.", "required": true, "update_allowed": false, "type": "string", "immutable": false, "constraints": [{"custom_constraint": "net_cidr"}]}, "mac_address": {"description": "MAC address to allow through this port.", "required": false, "update_allowed": false, "type": "string", "immutable": false, "constraints": [{"custom_constraint": "mac_addr"}]}}}}}, "admin_state_up": {"description": "The administrative state of this port.", "default": true, "required": false, "update_allowed": true, "type": "boolean", "immutable": false}, "binding:vnic_type": {"description": "The vnic type to be bound on the neutron port. To support SR-IOV PCI passthrough networking, you can request that the neutron port to be realized as normal (virtual nic), direct (pci passthrough), or macvtap (virtual interface with a tap-like software interface). Note that this only works for Neutron deployments that support the bindings extension.", "required": false, "update_allowed": true, "type": "string", "immutable": false, "constraints": [{"allowed_values": ["normal", "direct", "macvtap"]}]}, "device_owner": {"update_allowed": true, "required": false, "type": "string", "description": "Name of the network owning the port. The value is typically network:floatingip or network:router_interface or network:dhcp.", "immutable": false}, "value_specs": {"description": "Extra parameters to include in the request.", "default": {}, "required": false, "update_allowed": true, "type": "map", "immutable": false}, "mac_address": {"description": "MAC address to give to this port.", "required": false, "update_allowed": false, "type": "string", "immutable": false, "constraints": [{"custom_constraint": "mac_addr"}]}, "port_security_enabled": {"update_allowed": true, "required": false, "type": "boolean", "description": "Flag to enable/disable port security on the port. When disable this feature(set it to False), there will be no packages filtering, like security-group and address-pairs.", "immutable": false}, "qos_policy": {"description": "The name or ID of QoS policy to attach to this port.", "required": false, "update_allowed": true, "type": "string", "immutable": false, "constraints": [{"custom_constraint": "neutron.qos_policy"}]}, "device_id": {"update_allowed": true, "required": false, "type": "string", "description": "Device ID of this port.", "immutable": false}, "fixed_ips": {"description": "Desired IPs for this port.", "required": false, "update_allowed": true, "type": "list", "immutable": false, "schema": {"*": {"update_allowed": false, "required": false, "type": "map", "immutable": false, "schema": {"subnet_id": {"update_allowed": false, "required": false, "type": "string", "immutable": false, "constraints": [{"custom_constraint": "neutron.subnet"}]}, "subnet": {"description": "Subnet in which to allocate the IP address for this port.", "required": false, "update_allowed": false, "type": "string", "immutable": false, "constraints": [{"custom_constraint": "neutron.subnet"}]}, "ip_address": {"description": "IP address desired in the subnet for this port.", "required": false, "update_allowed": false, "type": "string", "immutable": false, "constraints": [{"custom_constraint": "ip_addr"}]}}}}}, "security_groups": {"update_allowed": true, "required": false, "type": "list", "description": "Security group IDs to associate with this port.", "immutable": false}, "network": {"description": "Network this port belongs to. If you plan to use current port to assign Floating IP, you should specify fixed_ips with subnet. Note if this changes to a different network update, the port will be replaced.", "required": true, "update_allowed": false, "type": "string", "immutable": false, "constraints": [{"custom_constraint": "neutron.network"}]}}, "resource_type": "OS::Neutron::Port"}
 _http_log_response /usr/lib/python2.7/dist-packages/keystoneclient/session.py:231
2017-03-06 22:07:44.743 6417 DEBUG tacker.vm.infra_drivers.heat.heat [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] vnfd_yaml template_name: sample-vnfd
description: demo-example

service_properties:
  Id: sample-vnfd
  vendor: tacker
  version: 1

vdus:
  vdu1:
    id: vdu1
    vm_image: Cirros
    instance_type: m1.tiny

    network_interfaces:
      management:
        network: 7918b3b3-6810-435b-970c-7e3e68f6c439
        management: true

    placement_policy:
      availability_zone: nova

    config:
      param0: key0
      param1: key1
 create /usr/local/lib/python2.7/dist-packages/tacker/vm/infra_drivers/heat/heat.py:282
2017-03-06 22:07:44.747 6417 DEBUG tacker.vm.infra_drivers.heat.heat [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] vnfd_dict OrderedDict([('template_name', 'sample-vnfd'), ('description', 'demo-example'), ('service_properties', OrderedDict([('Id', 'sample-vnfd'), ('vendor', 'tacker'), ('version', 1)])), ('vdus', OrderedDict([('vdu1', OrderedDict([('id', 'vdu1'), ('vm_image', 'Cirros'), ('instance_type', 'm1.tiny'), ('network_interfaces', OrderedDict([('management', OrderedDict([('network', '7918b3b3-6810-435b-970c-7e3e68f6c439'), ('management', True)]))])), ('placement_policy', OrderedDict([('availability_zone', 'nova')])), ('config', OrderedDict([('param0', 'key0'), ('param1', 'key1')]))]))]))]) create /usr/local/lib/python2.7/dist-packages/tacker/vm/infra_drivers/heat/heat.py:285
2017-03-06 22:07:44.748 6417 DEBUG tacker.common.log [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] tacker.vm.infra_drivers.heat.heat.DeviceHeat method _process_vdu_network_interfaces called with arguments ('vdu1', OrderedDict([('id', 'vdu1'), ('vm_image', 'Cirros'), ('instance_type', 'm1.tiny'), ('network_interfaces', OrderedDict([('management', OrderedDict([('network', '7918b3b3-6810-435b-970c-7e3e68f6c439'), ('management', True)]))])), ('placement_policy', OrderedDict([('availability_zone', 'nova')])), ('config', OrderedDict([('param0', 'key0'), ('param1', 'key1')]))]), {'image': 'Cirros', 'flavor': 'm1.tiny'}, {'outputs': {}, 'heat_template_version': datetime.date(2013, 5, 23), 'description': 'demo-example', 'resources': {'vdu1': {'type': 'OS::Nova::Server', 'properties': {'image': 'Cirros', 'flavor': 'm1.tiny'}}}}, {}) {} wrapper /usr/local/lib/python2.7/dist-packages/tacker/common/log.py:32
2017-03-06 22:07:44.752 6417 DEBUG tacker.vm.infra_drivers.heat.heat [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] service_context: [] create /usr/local/lib/python2.7/dist-packages/tacker/vm/infra_drivers/heat/heat.py:407
2017-03-06 22:07:44.752 6417 DEBUG tacker.vm.infra_drivers.heat.heat [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] fields: {'stack_name': 'tacker.vm.infra_drivers.heat.heat_DeviceHeat-c75772ad-cfb6-42a3-b17a-4f43cdffb0dd', 'template': 'description: demo-example\nheat_template_version: 2013-05-23\noutputs:\n mgmt_ip-vdu1:\n description: management ip address\n value:\n get_attr: [vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port, fixed_ips, 0, ip_address]\nresources:\n vdu1:\n properties:\n availability_zone: nova\n config_drive: true\n flavor: m1.tiny\n image: Cirros\n metadata: {param0: key0, param1: key1}\n networks:\n - port: {get_resource: vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port}\n type: OS::Nova::Server\n vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port:\n properties:\n fixed_ips: []\n network: 7918b3b3-6810-435b-970c-7e3e68f6c439\n port_security_enabled: false\n type: OS::Neutron::Port\n'} create /usr/local/lib/python2.7/dist-packages/tacker/vm/infra_drivers/heat/heat.py:409
2017-03-06 22:07:44.753 6417 DEBUG tacker.vm.infra_drivers.heat.heat [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] template: description: demo-example
heat_template_version: 2013-05-23
outputs:
  mgmt_ip-vdu1:
    description: management ip address
    value:
      get_attr: [vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port, fixed_ips, 0, ip_address]
resources:
  vdu1:
    properties:
      availability_zone: nova
      config_drive: true
      flavor: m1.tiny
      image: Cirros
      metadata: {param0: key0, param1: key1}
      networks:
      - port: {get_resource: vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port}
    type: OS::Nova::Server
  vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port:
    properties:
      fixed_ips: []
      network: 7918b3b3-6810-435b-970c-7e3e68f6c439
      port_security_enabled: false
    type: OS::Neutron::Port
 create /usr/local/lib/python2.7/dist-packages/tacker/vm/infra_drivers/heat/heat.py:410
2017-03-06 22:07:44.754 6417 DEBUG keystoneclient.session [-] REQ: curl -g -i -X POST http://controler:8004/v1/1dfdb8d3adc64559a2870bb086c441b6/stacks -H "User-Agent: python-heatclient" -H "Content-Type: application/json" -H "Accept: application/json" -H "X-Auth-Token: {SHA1}d1cf5e6df74d60be373f089301fc6810bcb0c651" -d '{"stack_name": "tacker.vm.infra_drivers.heat.heat_DeviceHeat-c75772ad-cfb6-42a3-b17a-4f43cdffb0dd", "disable_rollback": true, "template": "description: demo-example\nheat_template_version: 2013-05-23\noutputs:\n mgmt_ip-vdu1:\n description: management ip address\n value:\n get_attr: [vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port, fixed_ips, 0, ip_address]\nresources:\n vdu1:\n properties:\n availability_zone: nova\n config_drive: true\n flavor: m1.tiny\n image: Cirros\n metadata: {param0: key0, param1: key1}\n networks:\n - port: {get_resource: vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port}\n type: OS::Nova::Server\n vdu1-7918b3b3-6810-435b-970c-7e3e68f6c439-port:\n properties:\n fixed_ips: []\n network: 7918b3b3-6810-435b-970c-7e3e68f6c439\n port_security_enabled: false\n type: OS::Neutron::Port\n", "timeout_mins": 10}' _http_log_request /usr/lib/python2.7/dist-packages/keystoneclient/session.py:206
2017-03-06 22:07:45.201 6417 DEBUG requests.packages.urllib3.connectionpool [-] http://controler:8004 "POST /v1/1dfdb8d3adc64559a2870bb086c441b6/stacks HTTP/1.1" 400 348 _make_request /usr/local/lib/python2.7/dist-packages/requests/packages/urllib3/connectionpool.py:395
2017-03-06 22:07:45.202 6417 DEBUG keystoneclient.session [-] RESP: [400] Content-Type: application/json; charset=UTF-8 Content-Length: 348 X-Openstack-Request-Id: req-2d9ec5ca-672e-4ce1-9f4c-024afd11bbbd Date: Mon, 06 Mar 2017 16:37:45 GMT Connection: keep-alive
RESP BODY: {"explanation": "The server could not comply with the request since it is either malformed or otherwise incorrect.", "code": 400, "error": {"message": "Property error: : resources.vdu1.properties.image: : \"Cirros\" does not validate glance.image (constraint not found)", "traceback": null, "type": "StackValidationFailed"}, "title": "Bad Request"}
 _http_log_response /usr/lib/python2.7/dist-packages/keystoneclient/session.py:231
2017-03-06 22:07:45.209 6417 DEBUG tacker.db.vm.vm_db [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] device_db <tacker.db.vm.vm_db.Device[object at 7f8ddeb36890] {tenant_id=u'1dfdb8d3adc64559a2870bb086c441b6', id=u'c75772ad-cfb6-42a3-b17a-4f43cdffb0dd', template_id=u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', name=u'firstvnf', description=u'demo-example', instance_id=None, mgmt_url=None, status='PENDING_DELETE', vim_id=u'aed4074f-7df2-424e-87b1-d013aeb50e7d', placement_attr={'vim_name': u'localdev'}}> _make_device_dict /usr/local/lib/python2.7/dist-packages/tacker/db/vm/vm_db.py:193
2017-03-06 22:07:45.211 6417 DEBUG tacker.db.vm.vm_db [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] device_db attributes [] _make_device_dict /usr/local/lib/python2.7/dist-packages/tacker/db/vm/vm_db.py:194
2017-03-06 22:07:45.220 6417 DEBUG tacker.vm.vim_client [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] VIM info found for vim id aed4074f-7df2-424e-87b1-d013aeb50e7d get_vim /usr/local/lib/python2.7/dist-packages/tacker/vm/vim_client.py:62
2017-03-06 22:07:45.221 6417 DEBUG tacker.vm.vim_client [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] VIM id is aed4074f-7df2-424e-87b1-d013aeb50e7d _build_vim_auth /usr/local/lib/python2.7/dist-packages/tacker/vm/vim_client.py:77
2017-03-06 22:07:45.221 6417 DEBUG tacker.vm.vim_client [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] Attempting to open key file for vim id aed4074f-7df2-424e-87b1-d013aeb50e7d _find_vim_key /usr/local/lib/python2.7/dist-packages/tacker/vm/vim_client.py:101
2017-03-06 22:07:45.222 6417 DEBUG tacker.vm.monitor [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] deleting device_id c75772ad-cfb6-42a3-b17a-4f43cdffb0dd delete_hosting_vnf /usr/local/lib/python2.7/dist-packages/tacker/vm/monitor.py:112
2017-03-06 22:07:45.224 6417 DEBUG tacker.vm.mgmt_drivers.noop [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] mgmt_device_call {'status': 'PENDING_DELETE', 'device_template': {'service_types': [{'service_type': u'vnfd', 'id': u'ae2cc76c-8b4f-43c7-8471-7dcd15cc95eb'}], 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'mgmt_driver': u'noop', 'infra_driver': u'heat', 'attributes': {u'vnfd': u'template_name: sample-vnfd\ndescription: demo-example\n\nservice_properties:\n Id: sample-vnfd\n vendor: tacker\n version: 1\n\nvdus:\n vdu1:\n id: vdu1\n vm_image: Cirros\n instance_type: m1.tiny\n\n network_interfaces:\n management:\n network: 7918b3b3-6810-435b-970c-7e3e68f6c439\n management: true\n\n placement_policy:\n availability_zone: nova\n\n config:\n param0: key0\n param1: key1\n'}, 'id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'testvnf1'}, 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'vim_id': u'aed4074f-7df2-424e-87b1-d013aeb50e7d', 'id': u'c75772ad-cfb6-42a3-b17a-4f43cdffb0dd', 'instance_id': None, 'mgmt_url': None, 'placement_attr': {'vim_name': u'localdev'}, 'attributes': {}, 'template_id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'firstvnf'} {'action': 'delete_device', 'kwargs': {'device': {'status': 'PENDING_DELETE', 'device_template': {'service_types': [{'service_type': u'vnfd', 'id': u'ae2cc76c-8b4f-43c7-8471-7dcd15cc95eb'}], 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'mgmt_driver': u'noop', 'infra_driver': u'heat', 'attributes': {u'vnfd': u'template_name: sample-vnfd\ndescription: demo-example\n\nservice_properties:\n Id: sample-vnfd\n vendor: tacker\n version: 1\n\nvdus:\n vdu1:\n id: vdu1\n vm_image: Cirros\n instance_type: m1.tiny\n\n network_interfaces:\n management:\n network: 7918b3b3-6810-435b-970c-7e3e68f6c439\n management: true\n\n placement_policy:\n availability_zone: nova\n\n config:\n param0: key0\n param1: key1\n'}, 'id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'testvnf1'}, 'description': u'demo-example', 'tenant_id': u'1dfdb8d3adc64559a2870bb086c441b6', 'vim_id': u'aed4074f-7df2-424e-87b1-d013aeb50e7d', 'id': u'c75772ad-cfb6-42a3-b17a-4f43cdffb0dd', 'instance_id': None, 'mgmt_url': None, 'placement_attr': {'vim_name': u'localdev'}, 'attributes': {}, 'template_id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'name': u'firstvnf'}}} mgmt_call /usr/local/lib/python2.7/dist-packages/tacker/vm/mgmt_drivers/noop.py:44
2017-03-06 22:07:45.231 6417 ERROR tacker.api.v1.resource [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] create failed
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource Traceback (most recent call last):
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/api/v1/resource.py", line 89, in resource
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource result = method(request=request, **args)
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/api/v1/base.py", line 395, in create
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource obj = obj_creator(request.context, **kwargs)
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/vm/plugin.py", line 403, in create_vnf
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource vnf_dict = self.create_device(context, vnf)
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/vm/plugin.py", line 274, in create_device
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource device_dict = self._create_device(context, device_info, vim_auth)
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/vm/plugin.py", line 262, in _create_device
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource self.delete_device(context, device_id)
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/openstack/common/excutils.py", line 82, in __exit__
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource six.reraise(self.type_, self.value, self.tb)
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/vm/plugin.py", line 259, in _create_device
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource context=context, device=device_dict, auth_attr=vim_auth)
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/common/driver_manager.py", line 74, in invoke
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource return getattr(driver, method_name)(**kwargs)
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/common/log.py", line 33, in wrapper
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource return method(*args, **kwargs)
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/vm/infra_drivers/heat/heat.py", line 411, in create
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource stack = heatclient_.create(fields)
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource File "/usr/local/lib/python2.7/dist-packages/tacker/vm/infra_drivers/heat/heat.py", line 562, in create
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource raise vnfm.HeatClientException(msg=value)
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource HeatClientException: ERROR: Property error: : resources.vdu1.properties.image: : "Cirros" does not validate glance.image (constraint not found)
2017-03-06 22:07:45.231 6417 TRACE tacker.api.v1.resource
2017-03-06 22:07:45.233 6417 INFO tacker.wsgi [req-a51ae035-e61d-4944-9ddc-8fdb338e155d None] 10.139.4.100 - - [06/Mar/2017 22:07:45] "POST /v1.0/vnfs.json HTTP/1.1" 500 434 1.083929

2017-03-06 22:08:01.926 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 39401)

2017-03-06 22:08:01.928 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 22:08:01.930 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 22:08:01.931 6417 DEBUG routes.middleware [-] Matched GET /vnfds.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 22:08:01.931 6417 DEBUG routes.middleware [-] Route path: '/vnfds.:(format)', defaults: {'action': u'index', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 22:08:01.931 6417 DEBUG routes.middleware [-] Match dict: {'action': u'index', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>, 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 22:08:01.941 6417 INFO tacker.wsgi [req-82110395-2aed-4dc2-9e9b-ea9daa7e255b None] 10.139.4.100 - - [06/Mar/2017 22:08:01] "GET /v1.0/vnfds.json HTTP/1.1" 200 988 0.013364

2017-03-06 22:08:06.961 6417 INFO tacker.wsgi [-] (6417) accepted ('10.139.4.100', 39409)

2017-03-06 22:08:06.963 6417 DEBUG keystonemiddleware.auth_token [-] Authenticating user token process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:490
2017-03-06 22:08:06.964 6417 DEBUG keystonemiddleware.auth_token [-] Received request from user: user_id 9fe0f2888cc343fb84e75fcacbe6c53d, project_id 1dfdb8d3adc64559a2870bb086c441b6, roles admin,user process_request /usr/lib/python2.7/dist-packages/keystonemiddleware/auth_token/__init__.py:769
2017-03-06 22:08:06.965 6417 DEBUG routes.middleware [-] Matched GET /vnfds/a4e93c57-e536-4c3a-9d84-d00ea4ff2777.json __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:105
2017-03-06 22:08:06.965 6417 DEBUG routes.middleware [-] Route path: '/vnfds/:(id).:(format)', defaults: {'action': u'show', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:107
2017-03-06 22:08:06.966 6417 DEBUG routes.middleware [-] Match dict: {'action': u'show', 'controller': <wsgify at 140247309048720 wrapping <function resource at 0x7f8ddf0972a8>>, 'id': u'a4e93c57-e536-4c3a-9d84-d00ea4ff2777', 'format': u'json'} __call__ /usr/lib/python2.7/dist-packages/routes/middleware.py:108
2017-03-06 22:08:06.975 6417 INFO tacker.wsgi [req-d3bd9663-ac77-4ca4-aa20-db6db9850c3e None] 10.139.4.100 - - [06/Mar/2017 22:08:06] "GET /v1.0/vnfds/a4e93c57-e536-4c3a-9d84-d00ea4ff2777.json HTTP/1.1" 200 985 0.012561

_______________________________________________________________________

Anyone has faced this error before with Tacker Mitaka installations? Please suggest the pointers if any.

Thanks,
Abhijeet Karve

Question information

Language:
English Edit question
Status:
Solved
For:
tacker Edit question
Assignee:
No assignee Edit question
Solved by:
Abhijeet
Solved:
Last query:
Last reply:
Revision history for this message
Abhijeet (abhijeet-karve) said :
#1

The reported issue got resolved by downgrading python-glanceclient from 2.6 to 2.5.
Command is: pip install 'python-glanceclient==2.5'
Restart heat service by /etc/init.d/heat-api heat-api-cfn heat-engine restart