2020-03-28 05:07:15.196 29199 INFO neutron.common.config [-] Logging enabled! 2020-03-28 05:07:15.196 29199 INFO neutron.common.config [-] /usr/bin/neutron-dhcp-agent version 12.1.2.dev57 2020-03-28 05:07:15.196 29199 DEBUG neutron.common.config [-] command line: /usr/bin/neutron-dhcp-agent --config-file /usr/share/neutron/neutron-dist.conf --config-file /etc/neutron/neutron.conf --config-file /etc/neutron/dhcp_agent.ini --config-dir /etc/neutron/conf.d/common --config-dir /etc/neutron/conf.d/neutron-dhcp-agent --log-file /var/log/neutron/dhcp-agent.log setup_logging /usr/lib/python2.7/site-packages/neutron/common/config.py:104 2020-03-28 05:07:15.371 29199 DEBUG neutron_lib.callbacks.manager [-] Subscribe: > rbac-policy before_create subscribe /usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:41 2020-03-28 05:07:15.372 29199 DEBUG neutron_lib.callbacks.manager [-] Subscribe: > rbac-policy before_update subscribe /usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:41 2020-03-28 05:07:15.372 29199 DEBUG neutron_lib.callbacks.manager [-] Subscribe: > rbac-policy before_delete subscribe /usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:41 2020-03-28 05:07:15.395 29199 DEBUG neutron_lib.callbacks.manager [-] Subscribe: > rbac-policy before_create subscribe /usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:41 2020-03-28 05:07:15.396 29199 DEBUG neutron_lib.callbacks.manager [-] Subscribe: > rbac-policy before_update subscribe /usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:41 2020-03-28 05:07:15.396 29199 DEBUG neutron_lib.callbacks.manager [-] Subscribe: > rbac-policy before_delete subscribe /usr/lib/python2.7/site-packages/neutron_lib/callbacks/manager.py:41 2020-03-28 05:07:15.472 29199 DEBUG oslo_concurrency.lockutils [-] Acquired semaphore "singleton_lock" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:212 2020-03-28 05:07:15.472 29199 DEBUG oslo_concurrency.lockutils [-] Releasing semaphore "singleton_lock" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:228 2020-03-28 05:07:15.473 29199 DEBUG oslo_service.service [-] Full set of CONF: _wait_for_exit_or_signal /usr/lib/python2.7/site-packages/oslo_service/service.py:303 2020-03-28 05:07:15.473 29199 DEBUG oslo_service.service [-] ******************************************************************************** log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2880 2020-03-28 05:07:15.473 29199 DEBUG oslo_service.service [-] Configuration options gathered from: log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2881 2020-03-28 05:07:15.473 29199 DEBUG oslo_service.service [-] command line args: ['--config-file', '/usr/share/neutron/neutron-dist.conf', '--config-file', '/etc/neutron/neutron.conf', '--config-file', '/etc/neutron/dhcp_agent.ini', '--config-dir', '/etc/neutron/conf.d/common', '--config-dir', '/etc/neutron/conf.d/neutron-dhcp-agent', '--log-file', '/var/log/neutron/dhcp-agent.log'] log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2882 2020-03-28 05:07:15.473 29199 DEBUG oslo_service.service [-] config files: ['/usr/share/neutron/neutron-dist.conf', '/etc/neutron/neutron.conf', '/etc/neutron/dhcp_agent.ini'] log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2884 2020-03-28 05:07:15.473 29199 DEBUG oslo_service.service [-] ================================================================================ log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2885 2020-03-28 05:07:15.473 29199 DEBUG oslo_service.service [-] agent_down_time = 75 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.473 29199 DEBUG oslo_service.service [-] allow_bulk = True log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.474 29199 DEBUG oslo_service.service [-] allow_overlapping_ips = True log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.474 29199 DEBUG oslo_service.service [-] api_extensions_path = log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.474 29199 DEBUG oslo_service.service [-] api_paste_config = /usr/share/neutron/api-paste.ini log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.474 29199 DEBUG oslo_service.service [-] api_workers = 4 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.474 29199 DEBUG oslo_service.service [-] auth_strategy = keystone log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.474 29199 DEBUG oslo_service.service [-] backdoor_port = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.474 29199 DEBUG oslo_service.service [-] backdoor_socket = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.474 29199 DEBUG oslo_service.service [-] backlog = 4096 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.475 29199 DEBUG oslo_service.service [-] base_mac = fa:16:3e:00:00:00 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.475 29199 DEBUG oslo_service.service [-] bind_host = 192.168.24.1 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.475 29199 DEBUG oslo_service.service [-] bind_port = 9696 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.475 29199 DEBUG oslo_service.service [-] client_socket_timeout = 900 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.475 29199 DEBUG oslo_service.service [-] config_dir = ['/etc/neutron/conf.d/neutron-dhcp-agent'] log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.475 29199 DEBUG oslo_service.service [-] config_file = ['/usr/share/neutron/neutron-dist.conf', '/etc/neutron/neutron.conf', '/etc/neutron/dhcp_agent.ini'] log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.475 29199 DEBUG oslo_service.service [-] control_exchange = neutron log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.476 29199 DEBUG oslo_service.service [-] core_plugin = ml2 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.476 29199 DEBUG oslo_service.service [-] debug = True log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.476 29199 DEBUG oslo_service.service [-] default_availability_zones = [] log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.476 29199 DEBUG oslo_service.service [-] default_log_levels = ['amqp=WARN', 'amqplib=WARN', 'boto=WARN', 'qpid=WARN', 'sqlalchemy=WARN', 'suds=INFO', 'oslo.messaging=INFO', 'oslo_messaging=INFO', 'iso8601=WARN', 'requests.packages.urllib3.connectionpool=WARN', 'urllib3.connectionpool=WARN', 'websocket=WARN', 'requests.packages.urllib3.util.retry=WARN', 'urllib3.util.retry=WARN', 'keystonemiddleware=WARN', 'routes.middleware=WARN', 'stevedore=WARN', 'taskflow=WARN', 'keystoneauth=WARN', 'oslo.cache=INFO', 'dogpile.core.dogpile=INFO', 'OFPHandler=INFO', 'OfctlService=INFO', 'ryu.base.app_manager=INFO', 'ryu.controller.controller=INFO', 'ovsdbapp.backend.ovs_idl.vlog=INFO'] log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.476 29199 DEBUG oslo_service.service [-] dhcp_agent_notification = True log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.476 29199 DEBUG oslo_service.service [-] dhcp_broadcast_reply = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.477 29199 DEBUG oslo_service.service [-] dhcp_confs = /var/lib/neutron/dhcp log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.477 29199 DEBUG oslo_service.service [-] dhcp_driver = neutron.agent.linux.dhcp.Dnsmasq log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.477 29199 DEBUG oslo_service.service [-] dhcp_lease_duration = 86400 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.477 29199 DEBUG oslo_service.service [-] dhcp_load_type = networks log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.477 29199 DEBUG oslo_service.service [-] dhcp_rebinding_time = 0 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.477 29199 DEBUG oslo_service.service [-] dhcp_renewal_time = 0 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.477 29199 DEBUG oslo_service.service [-] dns_domain = localdomain log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.477 29199 DEBUG oslo_service.service [-] dnsmasq_base_log_dir = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.478 29199 DEBUG oslo_service.service [-] dnsmasq_config_file = /etc/dnsmasq-ironic.conf log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.478 29199 DEBUG oslo_service.service [-] dnsmasq_dns_servers = [] log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.478 29199 DEBUG oslo_service.service [-] dnsmasq_lease_max = 16777216 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.478 29199 DEBUG oslo_service.service [-] dnsmasq_local_resolv = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.478 29199 DEBUG oslo_service.service [-] enable_isolated_metadata = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.478 29199 DEBUG oslo_service.service [-] enable_metadata_network = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.478 29199 DEBUG oslo_service.service [-] enable_new_agents = True log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.478 29199 DEBUG oslo_service.service [-] external_dns_driver = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.479 29199 DEBUG oslo_service.service [-] external_pids = /var/lib/neutron/external/pids log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.479 29199 DEBUG oslo_service.service [-] force_metadata = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.479 29199 DEBUG oslo_service.service [-] global_physnet_mtu = 1350 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.479 29199 DEBUG oslo_service.service [-] graceful_shutdown_timeout = 60 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.479 29199 DEBUG oslo_service.service [-] host = undercloud.localdomain log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.479 29199 DEBUG oslo_service.service [-] instance_format = [instance: %(uuid)s] log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.479 29199 DEBUG oslo_service.service [-] instance_uuid_format = [instance: %(uuid)s] log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.480 29199 DEBUG oslo_service.service [-] interface_driver = neutron.agent.linux.interface.OVSInterfaceDriver log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.480 29199 DEBUG oslo_service.service [-] ipam_driver = internal log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.480 29199 DEBUG oslo_service.service [-] ipv6_pd_enabled = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.480 29199 DEBUG oslo_service.service [-] log_config_append = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.480 29199 DEBUG oslo_service.service [-] log_date_format = %Y-%m-%d %H:%M:%S log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.480 29199 DEBUG oslo_service.service [-] log_dir = /var/log/neutron log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.480 29199 DEBUG oslo_service.service [-] log_file = /var/log/neutron/dhcp-agent.log log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.480 29199 DEBUG oslo_service.service [-] log_options = True log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.481 29199 DEBUG oslo_service.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/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.481 29199 DEBUG oslo_service.service [-] logging_debug_format_suffix = %(funcName)s %(pathname)s:%(lineno)d log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.481 29199 DEBUG oslo_service.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/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.481 29199 DEBUG oslo_service.service [-] logging_exception_prefix = %(asctime)s.%(msecs)03d %(process)d ERROR %(name)s %(instance)s log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.481 29199 DEBUG oslo_service.service [-] logging_user_identity_format = %(user)s %(tenant)s %(domain)s %(user_domain)s %(project_domain)s log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.481 29199 DEBUG oslo_service.service [-] max_dns_nameservers = 5 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.481 29199 DEBUG oslo_service.service [-] max_header_line = 16384 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.481 29199 DEBUG oslo_service.service [-] max_subnet_host_routes = 20 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.482 29199 DEBUG oslo_service.service [-] metadata_proxy_group = log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.482 29199 DEBUG oslo_service.service [-] metadata_proxy_socket = /var/lib/neutron/metadata_proxy log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.482 29199 DEBUG oslo_service.service [-] metadata_proxy_user = log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.482 29199 DEBUG oslo_service.service [-] network_link_prefix = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.482 29199 DEBUG oslo_service.service [-] notify_nova_on_port_data_changes = True log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.482 29199 DEBUG oslo_service.service [-] notify_nova_on_port_status_changes = True log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.482 29199 DEBUG oslo_service.service [-] num_sync_threads = 4 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.483 29199 DEBUG oslo_service.service [-] ovs_integration_bridge = br-int log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.483 29199 DEBUG oslo_service.service [-] ovs_use_veth = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.483 29199 DEBUG oslo_service.service [-] pagination_max_limit = -1 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.483 29199 DEBUG oslo_service.service [-] periodic_fuzzy_delay = 5 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.483 29199 DEBUG oslo_service.service [-] periodic_interval = 40 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.483 29199 DEBUG oslo_service.service [-] publish_errors = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.483 29199 DEBUG oslo_service.service [-] rate_limit_burst = 0 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.483 29199 DEBUG oslo_service.service [-] rate_limit_except_level = CRITICAL log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.484 29199 DEBUG oslo_service.service [-] rate_limit_interval = 0 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.484 29199 DEBUG oslo_service.service [-] resync_interval = 30 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.484 29199 DEBUG oslo_service.service [-] retry_until_window = 30 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.484 29199 DEBUG oslo_service.service [-] rpc_backend = rabbit log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.484 29199 DEBUG oslo_service.service [-] rpc_response_timeout = 60 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.484 29199 DEBUG oslo_service.service [-] rpc_state_report_workers = 1 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.484 29199 DEBUG oslo_service.service [-] rpc_workers = 4 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.484 29199 DEBUG oslo_service.service [-] run_external_periodic_tasks = True log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.485 29199 DEBUG oslo_service.service [-] send_events_interval = 2 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.485 29199 DEBUG oslo_service.service [-] service_plugins = ['segments'] log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.485 29199 DEBUG oslo_service.service [-] state_path = /var/lib/neutron log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.485 29199 DEBUG oslo_service.service [-] syslog_log_facility = LOG_USER log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.485 29199 DEBUG oslo_service.service [-] tcp_keepidle = 600 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.485 29199 DEBUG oslo_service.service [-] transport_url = **** log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.485 29199 DEBUG oslo_service.service [-] use_journal = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.485 29199 DEBUG oslo_service.service [-] use_json = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.486 29199 DEBUG oslo_service.service [-] use_ssl = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.486 29199 DEBUG oslo_service.service [-] use_stderr = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.486 29199 DEBUG oslo_service.service [-] use_syslog = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.486 29199 DEBUG oslo_service.service [-] vlan_transparent = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.486 29199 DEBUG oslo_service.service [-] watch_log_file = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.486 29199 DEBUG oslo_service.service [-] wsgi_default_pool_size = 100 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.486 29199 DEBUG oslo_service.service [-] wsgi_keep_alive = True log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.486 29199 DEBUG oslo_service.service [-] wsgi_log_format = %(client_ip)s "%(request_line)s" status: %(status_code)s len: %(body_length)s time: %(wall_seconds).7f log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2894 2020-03-28 05:07:15.487 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.amqp_auto_delete = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.487 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.amqp_durable_queues = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.487 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.conn_pool_min_size = 2 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.487 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.conn_pool_ttl = 1200 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.487 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.fake_rabbit = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.487 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.heartbeat_rate = 2 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.487 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.heartbeat_timeout_threshold = 60 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.488 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.kombu_compression = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.488 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.kombu_failover_strategy = round-robin log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.488 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.kombu_missing_consumer_retry_timeout = 60 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.490 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.kombu_reconnect_delay = 1.0 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.490 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.rabbit_ha_queues = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.490 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.rabbit_host = localhost log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.491 29199 WARNING oslo_config.cfg [-] Option "rabbit_hosts" from group "oslo_messaging_rabbit" is deprecated for removal (Replaced by [DEFAULT]/transport_url). Its value may be silently ignored in the future. 2020-03-28 05:07:15.491 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.rabbit_hosts = ['192.168.24.1'] log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.491 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.rabbit_interval_max = 30 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.491 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.rabbit_login_method = AMQPLAIN log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.491 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.rabbit_max_retries = 0 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.491 29199 WARNING oslo_config.cfg [-] Option "rabbit_password" from group "oslo_messaging_rabbit" is deprecated for removal (Replaced by [DEFAULT]/transport_url). Its value may be silently ignored in the future. 2020-03-28 05:07:15.491 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.rabbit_password = **** log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.492 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.rabbit_port = 5672 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.492 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.rabbit_qos_prefetch_count = 0 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.492 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.rabbit_retry_backoff = 2 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.492 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.rabbit_retry_interval = 1 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.492 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.rabbit_transient_queues_ttl = 1800 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.492 29199 WARNING oslo_config.cfg [-] Option "rabbit_userid" from group "oslo_messaging_rabbit" is deprecated for removal (Replaced by [DEFAULT]/transport_url). Its value may be silently ignored in the future. 2020-03-28 05:07:15.492 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.rabbit_userid = 06aa1a181f4eafe469d9e4b6bd29334f4e9331c1 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.493 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.rabbit_virtual_host = / log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.493 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.rpc_conn_pool_size = 30 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.493 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.ssl = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.493 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.ssl_ca_file = log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.493 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.ssl_cert_file = log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.493 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.ssl_key_file = log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.493 29199 DEBUG oslo_service.service [-] oslo_messaging_rabbit.ssl_version = log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.494 29199 DEBUG oslo_service.service [-] nova.auth_section = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.494 29199 DEBUG oslo_service.service [-] nova.auth_type = password log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.494 29199 DEBUG oslo_service.service [-] nova.cafile = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.494 29199 DEBUG oslo_service.service [-] nova.certfile = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.494 29199 DEBUG oslo_service.service [-] nova.endpoint_type = public log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.494 29199 DEBUG oslo_service.service [-] nova.insecure = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.494 29199 DEBUG oslo_service.service [-] nova.keyfile = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.495 29199 DEBUG oslo_service.service [-] nova.region_name = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.495 29199 DEBUG oslo_service.service [-] nova.timeout = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.495 29199 DEBUG oslo_service.service [-] placement.auth_section = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.495 29199 DEBUG oslo_service.service [-] placement.auth_type = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.495 29199 DEBUG oslo_service.service [-] placement.cafile = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.495 29199 DEBUG oslo_service.service [-] placement.certfile = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.495 29199 DEBUG oslo_service.service [-] placement.endpoint_type = public log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.495 29199 DEBUG oslo_service.service [-] placement.insecure = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.496 29199 DEBUG oslo_service.service [-] placement.keyfile = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.496 29199 DEBUG oslo_service.service [-] placement.region_name = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.496 29199 DEBUG oslo_service.service [-] placement.timeout = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.496 29199 DEBUG oslo_service.service [-] oslo_messaging_notifications.driver = ['noop'] log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.496 29199 DEBUG oslo_service.service [-] oslo_messaging_notifications.retry = -1 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.496 29199 DEBUG oslo_service.service [-] oslo_messaging_notifications.topics = ['notifications'] log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.496 29199 DEBUG oslo_service.service [-] oslo_messaging_notifications.transport_url = **** log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.497 29199 DEBUG oslo_service.service [-] QUOTAS.default_quota = -1 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.497 29199 DEBUG oslo_service.service [-] QUOTAS.quota_driver = neutron.db.quota.driver.DbQuotaDriver log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.497 29199 DEBUG oslo_service.service [-] QUOTAS.quota_network = 100 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.497 29199 DEBUG oslo_service.service [-] QUOTAS.quota_port = -1 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.497 29199 DEBUG oslo_service.service [-] QUOTAS.quota_rbac_policy = 10 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.497 29199 DEBUG oslo_service.service [-] QUOTAS.quota_security_group = 10 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.497 29199 DEBUG oslo_service.service [-] QUOTAS.quota_security_group_rule = 100 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.498 29199 DEBUG oslo_service.service [-] QUOTAS.quota_subnet = 100 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.498 29199 DEBUG oslo_service.service [-] QUOTAS.track_quota_usage = True log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.498 29199 DEBUG oslo_service.service [-] AGENT.availability_zone = nova log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.498 29199 DEBUG oslo_service.service [-] AGENT.check_child_processes_action = respawn log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.498 29199 DEBUG oslo_service.service [-] AGENT.check_child_processes_interval = 60 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.498 29199 DEBUG oslo_service.service [-] AGENT.comment_iptables_rules = True log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.498 29199 DEBUG oslo_service.service [-] AGENT.debug_iptables_rules = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.499 29199 DEBUG oslo_service.service [-] AGENT.log_agent_heartbeats = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.499 29199 DEBUG oslo_service.service [-] AGENT.report_interval = 30.0 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.499 29199 DEBUG oslo_service.service [-] AGENT.root_helper = sudo neutron-rootwrap /etc/neutron/rootwrap.conf log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.499 29199 DEBUG oslo_service.service [-] AGENT.root_helper_daemon = sudo neutron-rootwrap-daemon /etc/neutron/rootwrap.conf log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.499 29199 DEBUG oslo_service.service [-] AGENT.use_helper_for_ns_read = True log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.499 29199 DEBUG oslo_service.service [-] profiler.connection_string = messaging:// log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.499 29199 DEBUG oslo_service.service [-] profiler.enabled = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.499 29199 DEBUG oslo_service.service [-] profiler.es_doc_type = notification log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.500 29199 DEBUG oslo_service.service [-] profiler.es_scroll_size = 10000 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.500 29199 DEBUG oslo_service.service [-] profiler.es_scroll_time = 2m log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.500 29199 DEBUG oslo_service.service [-] profiler.hmac_keys = SECRET_KEY log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.500 29199 DEBUG oslo_service.service [-] profiler.sentinel_service_name = mymaster log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.500 29199 DEBUG oslo_service.service [-] profiler.socket_timeout = 0.1 log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.500 29199 DEBUG oslo_service.service [-] profiler.trace_sqlalchemy = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.500 29199 DEBUG oslo_service.service [-] service_providers.service_provider = [] log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.501 29199 DEBUG oslo_service.service [-] oslo_concurrency.disable_process_locking = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.501 29199 DEBUG oslo_service.service [-] oslo_concurrency.lock_path = /var/lib/neutron/lock log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.501 29199 DEBUG oslo_service.service [-] oslo_versionedobjects.fatal_exception_format_errors = False log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.501 29199 DEBUG oslo_service.service [-] privsep.capabilities = [21, 12, 1, 2] log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.501 29199 DEBUG oslo_service.service [-] privsep.group = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.501 29199 DEBUG oslo_service.service [-] privsep.helper_command = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.502 29199 DEBUG oslo_service.service [-] privsep.user = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.502 29199 DEBUG oslo_service.service [-] xenapi.connection_password = **** log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.502 29199 DEBUG oslo_service.service [-] xenapi.connection_url = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.502 29199 DEBUG oslo_service.service [-] xenapi.connection_username = None log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2902 2020-03-28 05:07:15.502 29199 DEBUG oslo_service.service [-] ******************************************************************************** log_opt_values /usr/lib/python2.7/site-packages/oslo_config/cfg.py:2904 2020-03-28 05:07:15.514 29199 INFO neutron.agent.dhcp.agent [-] Synchronizing state 2020-03-28 05:08:15.520 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" acquired by "neutron.agent.linux.external_process._check_child_processes" :: waited 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273 2020-03-28 05:08:15.523 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" released by "neutron.agent.linux.external_process._check_child_processes" :: held 0.003s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent [req-7eb9403b-bb4f-4a20-ada4-6c8d442cecd1 - - - - -] Failed reporting state!: MessagingTimeout: Timed out waiting for a reply to message ID dcbf037400174acb97c0c6dd6aeaa27e 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent Traceback (most recent call last): 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py", line 863, in _report_state 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent ctx, self.agent_state, True) 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/neutron/agent/rpc.py", line 93, in report_state 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent return method(context, 'report_state', **kwargs) 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 174, in call 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent retry=self.retry) 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 131, in _send 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent timeout=timeout, retry=retry) 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 625, in send 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent retry=retry) 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 614, in _send 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent result = self._waiter.wait(msg_id, timeout) 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 506, in wait 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent message = self.waiters.get(msg_id, timeout=timeout) 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 394, in get 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent 'to message ID %s' % msg_id) 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent MessagingTimeout: Timed out waiting for a reply to message ID dcbf037400174acb97c0c6dd6aeaa27e 2020-03-28 05:08:15.641 29199 ERROR neutron.agent.dhcp.agent 2020-03-28 05:08:15.647 29199 WARNING oslo.service.loopingcall [req-7eb9403b-bb4f-4a20-ada4-6c8d442cecd1 - - - - -] Function 'neutron.agent.dhcp.agent.DhcpAgentWithStateReport._report_state' run outlasted interval by 30.14 sec 2020-03-28 05:08:15.683 29199 ERROR neutron.common.rpc [req-e694110a-f4c3-437d-a12d-bc60a9539be3 - - - - -] Timeout in RPC method get_active_networks_info. Waiting for 28 seconds before next attempt. If the server is not down, consider increasing the rpc_response_timeout option as Neutron server(s) may be overloaded and unable to respond quickly enough.: MessagingTimeout: Timed out waiting for a reply to message ID 1b4c2964876b4d8f9505fe00050361cc 2020-03-28 05:08:15.684 29199 WARNING neutron.common.rpc [req-e694110a-f4c3-437d-a12d-bc60a9539be3 - - - - -] Increasing timeout for get_active_networks_info calls to 120 seconds. Restart the agent to restore it to the default value.: MessagingTimeout: Timed out waiting for a reply to message ID 1b4c2964876b4d8f9505fe00050361cc 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent [req-e694110a-f4c3-437d-a12d-bc60a9539be3 - - - - -] Unable to sync network state.: MessagingTimeout: Timed out waiting for a reply to message ID 1b4c2964876b4d8f9505fe00050361cc 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent Traceback (most recent call last): 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py", line 191, in sync_state 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent enable_dhcp_filter=False) 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py", line 695, in get_active_networks_info 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent host=self.host, **kwargs) 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/neutron/common/rpc.py", line 185, in call 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent time.sleep(wait) 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 220, in __exit__ 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent self.force_reraise() 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_utils/excutils.py", line 196, in force_reraise 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent six.reraise(self.type_, self.value, self.tb) 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/neutron/common/rpc.py", line 162, in call 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent return self._original_context.call(ctxt, method, **kwargs) 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 174, in call 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent retry=self.retry) 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 131, in _send 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent timeout=timeout, retry=retry) 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 625, in send 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent retry=retry) 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 614, in _send 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent result = self._waiter.wait(msg_id, timeout) 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 506, in wait 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent message = self.waiters.get(msg_id, timeout=timeout) 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 394, in get 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent 'to message ID %s' % msg_id) 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent MessagingTimeout: Timed out waiting for a reply to message ID 1b4c2964876b4d8f9505fe00050361cc 2020-03-28 05:08:43.397 29199 ERROR neutron.agent.dhcp.agent 2020-03-28 05:08:43.403 29199 DEBUG neutron.common.rpc [req-e694110a-f4c3-437d-a12d-bc60a9539be3 - - - - -] Creating Consumer connection for Service dhcp_agent start /usr/lib/python2.7/site-packages/neutron/common/rpc.py:293 2020-03-28 05:08:43.477 29199 INFO neutron.agent.dhcp.agent [req-e694110a-f4c3-437d-a12d-bc60a9539be3 - - - - -] DHCP agent started 2020-03-28 05:09:15.520 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" acquired by "neutron.agent.linux.external_process._check_child_processes" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273 2020-03-28 05:09:15.521 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" released by "neutron.agent.linux.external_process._check_child_processes" :: held 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent [req-a7d5c122-e930-4160-a104-758e044adc67 - - - - -] Failed reporting state!: MessagingTimeout: Timed out waiting for a reply to message ID 903ede32e82b444498cb09794e168efc 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent Traceback (most recent call last): 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py", line 863, in _report_state 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent ctx, self.agent_state, True) 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/neutron/agent/rpc.py", line 93, in report_state 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent return method(context, 'report_state', **kwargs) 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 174, in call 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent retry=self.retry) 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 131, in _send 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent timeout=timeout, retry=retry) 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 625, in send 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent retry=retry) 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 614, in _send 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent result = self._waiter.wait(msg_id, timeout) 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 506, in wait 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent message = self.waiters.get(msg_id, timeout=timeout) 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 394, in get 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent 'to message ID %s' % msg_id) 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent MessagingTimeout: Timed out waiting for a reply to message ID 903ede32e82b444498cb09794e168efc 2020-03-28 05:09:15.658 29199 ERROR neutron.agent.dhcp.agent 2020-03-28 05:09:15.660 29199 WARNING oslo.service.loopingcall [req-a7d5c122-e930-4160-a104-758e044adc67 - - - - -] Function 'neutron.agent.dhcp.agent.DhcpAgentWithStateReport._report_state' run outlasted interval by 30.01 sec 2020-03-28 05:10:15.523 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" acquired by "neutron.agent.linux.external_process._check_child_processes" :: waited 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273 2020-03-28 05:10:15.529 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" released by "neutron.agent.linux.external_process._check_child_processes" :: held 0.006s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent [req-eefdeadf-bcbd-4a92-a00e-a350bd0b30b9 - - - - -] Failed reporting state!: MessagingTimeout: Timed out waiting for a reply to message ID 7322b72accfb4962b7f88810508e1830 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent Traceback (most recent call last): 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py", line 863, in _report_state 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent ctx, self.agent_state, True) 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/neutron/agent/rpc.py", line 93, in report_state 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent return method(context, 'report_state', **kwargs) 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 174, in call 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent retry=self.retry) 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 131, in _send 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent timeout=timeout, retry=retry) 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 625, in send 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent retry=retry) 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 614, in _send 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent result = self._waiter.wait(msg_id, timeout) 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 506, in wait 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent message = self.waiters.get(msg_id, timeout=timeout) 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 394, in get 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent 'to message ID %s' % msg_id) 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent MessagingTimeout: Timed out waiting for a reply to message ID 7322b72accfb4962b7f88810508e1830 2020-03-28 05:10:15.666 29199 ERROR neutron.agent.dhcp.agent 2020-03-28 05:10:15.669 29199 WARNING oslo.service.loopingcall [req-eefdeadf-bcbd-4a92-a00e-a350bd0b30b9 - - - - -] Function 'neutron.agent.dhcp.agent.DhcpAgentWithStateReport._report_state' run outlasted interval by 30.01 sec 2020-03-28 05:11:15.524 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" acquired by "neutron.agent.linux.external_process._check_child_processes" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273 2020-03-28 05:11:15.525 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" released by "neutron.agent.linux.external_process._check_child_processes" :: held 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent [req-9c666cf3-d4c7-4154-9793-5d32ef6e7dd0 - - - - -] Failed reporting state!: MessagingTimeout: Timed out waiting for a reply to message ID e5f74128ce2044e29c068f536a34aea7 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent Traceback (most recent call last): 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py", line 863, in _report_state 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent ctx, self.agent_state, True) 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/neutron/agent/rpc.py", line 93, in report_state 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent return method(context, 'report_state', **kwargs) 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/rpc/client.py", line 174, in call 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent retry=self.retry) 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/transport.py", line 131, in _send 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent timeout=timeout, retry=retry) 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 625, in send 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent retry=retry) 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 614, in _send 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent result = self._waiter.wait(msg_id, timeout) 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 506, in wait 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent message = self.waiters.get(msg_id, timeout=timeout) 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent File "/usr/lib/python2.7/site-packages/oslo_messaging/_drivers/amqpdriver.py", line 394, in get 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent 'to message ID %s' % msg_id) 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent MessagingTimeout: Timed out waiting for a reply to message ID e5f74128ce2044e29c068f536a34aea7 2020-03-28 05:11:15.677 29199 ERROR neutron.agent.dhcp.agent 2020-03-28 05:11:15.679 29199 WARNING oslo.service.loopingcall [req-9c666cf3-d4c7-4154-9793-5d32ef6e7dd0 - - - - -] Function 'neutron.agent.dhcp.agent.DhcpAgentWithStateReport._report_state' run outlasted interval by 30.01 sec 2020-03-28 05:11:15.763 29199 DEBUG neutron.agent.dhcp.agent [-] Starting _process_loop _process_loop /usr/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:464 2020-03-28 05:11:45.763 29199 DEBUG neutron.agent.dhcp.agent [-] resync (*): [MessagingTimeout('Timed out waiting for a reply to message ID 1b4c2964876b4d8f9505fe00050361cc',)] _periodic_resync_helper /usr/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:261 2020-03-28 05:11:45.764 29199 INFO neutron.agent.dhcp.agent [-] Synchronizing state 2020-03-28 05:11:45.929 29199 INFO neutron.agent.dhcp.agent [req-32760ab5-10d9-4526-9d15-0c0c5f962d2c - - - - -] All active networks have been fetched through RPC. 2020-03-28 05:11:45.930 29199 INFO neutron.agent.dhcp.agent [req-32760ab5-10d9-4526-9d15-0c0c5f962d2c - - - - -] Synchronizing state complete 2020-03-28 05:12:15.524 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" acquired by "neutron.agent.linux.external_process._check_child_processes" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273 2020-03-28 05:12:15.525 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" released by "neutron.agent.linux.external_process._check_child_processes" :: held 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285 2020-03-28 05:13:15.525 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" acquired by "neutron.agent.linux.external_process._check_child_processes" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273 2020-03-28 05:13:15.526 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" released by "neutron.agent.linux.external_process._check_child_processes" :: held 0.002s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285 2020-03-28 05:14:15.525 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" acquired by "neutron.agent.linux.external_process._check_child_processes" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273 2020-03-28 05:14:15.527 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" released by "neutron.agent.linux.external_process._check_child_processes" :: held 0.002s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285 2020-03-28 05:15:15.526 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" acquired by "neutron.agent.linux.external_process._check_child_processes" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273 2020-03-28 05:15:15.528 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" released by "neutron.agent.linux.external_process._check_child_processes" :: held 0.002s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285 2020-03-28 05:16:07.836 29199 DEBUG neutron.agent.dhcp.agent [req-b5fd2fea-c70e-453e-989e-fb0a92cacc2c - - - - -] Calling driver for network: ab116a3d-4224-46e2-8085-6e8a116510df action: enable call_driver /usr/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:135 2020-03-28 05:16:07.898 29199 DEBUG neutron.agent.linux.utils [req-b5fd2fea-c70e-453e-989e-fb0a92cacc2c - - - - -] Unable to access /var/lib/neutron/dhcp/ab116a3d-4224-46e2-8085-6e8a116510df/pid get_value_from_file /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:250 2020-03-28 05:16:07.900 29199 DEBUG neutron.agent.linux.dhcp [req-b5fd2fea-c70e-453e-989e-fb0a92cacc2c - - - - -] DHCP port dhcp4ffb0b0c-492f-50f3-b91f-5f97b4a206be-ab116a3d-4224-46e2-8085-6e8a116510df on network ab116a3d-4224-46e2-8085-6e8a116510df does not yet exist. Checking for a reserved port. _setup_reserved_dhcp_port /usr/lib/python2.7/site-packages/neutron/agent/linux/dhcp.py:1371 2020-03-28 05:16:07.901 29199 DEBUG neutron.agent.linux.dhcp [req-b5fd2fea-c70e-453e-989e-fb0a92cacc2c - - - - -] DHCP port dhcp4ffb0b0c-492f-50f3-b91f-5f97b4a206be-ab116a3d-4224-46e2-8085-6e8a116510df on network ab116a3d-4224-46e2-8085-6e8a116510df does not yet exist. Creating new one. _setup_new_dhcp_port /usr/lib/python2.7/site-packages/neutron/agent/linux/dhcp.py:1385 2020-03-28 05:16:09.080 29199 INFO oslo.privsep.daemon [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running privsep helper: ['sudo', 'neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'privsep-helper', '--config-file', '/usr/share/neutron/neutron-dist.conf', '--config-file', '/etc/neutron/neutron.conf', '--config-file', '/etc/neutron/dhcp_agent.ini', '--config-dir', '/etc/neutron/conf.d/neutron-dhcp-agent', '--privsep_context', 'neutron.privileged.default', '--privsep_sock_path', '/tmp/tmpldOvOn/privsep.sock'] 2020-03-28 05:16:10.137 29199 INFO oslo.privsep.daemon [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Spawned new privsep daemon via rootwrap 2020-03-28 05:16:10.138 29199 DEBUG oslo.privsep.daemon [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Accepted privsep connection to /tmp/tmpldOvOn/privsep.sock __init__ /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:331 2020-03-28 05:16:10.029 4048 INFO oslo.privsep.daemon [-] privsep daemon starting 2020-03-28 05:16:10.037 4048 INFO oslo.privsep.daemon [-] privsep process running with uid/gid: 0/0 2020-03-28 05:16:10.067 4048 INFO oslo.privsep.daemon [-] privsep process running with capabilities (eff/prm/inh): CAP_DAC_OVERRIDE|CAP_DAC_READ_SEARCH|CAP_NET_ADMIN|CAP_SYS_ADMIN/CAP_DAC_OVERRIDE|CAP_DAC_READ_SEARCH|CAP_NET_ADMIN|CAP_SYS_ADMIN/none 2020-03-28 05:16:10.068 4048 INFO oslo.privsep.daemon [-] privsep daemon running as pid 4048 2020-03-28 05:16:10.139 4048 DEBUG oslo.privsep.daemon [-] privsep: request[140502267199568]: (1,) loop /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:443 2020-03-28 05:16:10.140 4048 DEBUG oslo.privsep.daemon [-] privsep: reply[140502267199568]: (2,) loop /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:456 2020-03-28 05:16:10.140 4048 DEBUG oslo.privsep.daemon [-] privsep: request[140502267199568]: (3, 'neutron.privileged.agent.linux.ip_lib.list_netns', (), {}) loop /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:443 2020-03-28 05:16:10.330 4048 DEBUG oslo.privsep.daemon [-] privsep: reply[140502267199568]: (4, []) loop /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:456 2020-03-28 05:16:10.332 4048 DEBUG oslo.privsep.daemon [-] privsep: request[140502267199568]: (3, 'neutron.privileged.agent.linux.ip_lib.create_netns', (u'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df',), {}) loop /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:443 2020-03-28 05:16:10.359 4048 DEBUG oslo.privsep.daemon [-] privsep: reply[140502267199568]: (4, None) loop /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:456 2020-03-28 05:16:10.360 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'sysctl', '-w', 'net.ipv4.conf.all.promote_secondaries=1'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:10.369 29199 DEBUG oslo_rootwrap.client [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Popen for ['sudo', 'neutron-rootwrap-daemon', '/etc/neutron/rootwrap.conf'] command has been instantiated _initialize /usr/lib/python2.7/site-packages/oslo_rootwrap/client.py:73 2020-03-28 05:16:10.563 29199 INFO oslo_rootwrap.client [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Spawned new rootwrap daemon process with pid=4053 2020-03-28 05:16:10.615 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip', 'link', 'set', 'lo', 'up'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:10.635 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'sysctl', '-w', 'net.ipv4.ip_nonlocal_bind=1'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:10.662 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'sysctl', '-w', 'net.ipv6.conf.default.accept_ra=0'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:10.683 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip', '-o', 'link', 'show', 'tap01d47a8b-5a'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:10.723 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip', '-o', 'link', 'show', 'tap01d47a8b-5a'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:10.752 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command: ['ip', '-o', 'link', 'show', 'br-int'] create_process /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:87 2020-03-28 05:16:11.090 29199 DEBUG ovsdbapp.backend.ovs_idl.transaction [-] Running txn command(idx=0): DelPortCommand(if_exists=True, bridge=None, port=tap01d47a8b-5a) do_commit /usr/lib/python2.7/site-packages/ovsdbapp/backend/ovs_idl/transaction.py:84 2020-03-28 05:16:11.091 29199 DEBUG ovsdbapp.backend.ovs_idl.transaction [-] Transaction caused no change do_commit /usr/lib/python2.7/site-packages/ovsdbapp/backend/ovs_idl/transaction.py:121 2020-03-28 05:16:11.092 29199 DEBUG ovsdbapp.backend.ovs_idl.transaction [-] Running txn command(idx=0): AddPortCommand(bridge=br-int, may_exist=False, port=tap01d47a8b-5a) do_commit /usr/lib/python2.7/site-packages/ovsdbapp/backend/ovs_idl/transaction.py:84 2020-03-28 05:16:11.093 29199 DEBUG ovsdbapp.backend.ovs_idl.transaction [-] Running txn command(idx=1): DbSetCommand(table=Port, col_values=(('tag', 4095),), record=tap01d47a8b-5a) do_commit /usr/lib/python2.7/site-packages/ovsdbapp/backend/ovs_idl/transaction.py:84 2020-03-28 05:16:11.100 29199 DEBUG ovsdbapp.backend.ovs_idl.transaction [-] Running txn command(idx=2): DbSetCommand(table=Interface, col_values=(('type', 'internal'), ('external_ids', {'iface-id': u'01d47a8b-5a85-4e50-9790-3b38d3378565', 'iface-status': 'active', 'attached-mac': u'fa:16:3e:2b:00:83'})), record=tap01d47a8b-5a) do_commit /usr/lib/python2.7/site-packages/ovsdbapp/backend/ovs_idl/transaction.py:84 2020-03-28 05:16:11.122 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'link', 'set', 'tap01d47a8b-5a', 'address', 'fa:16:3e:2b:00:83'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:11.139 4048 DEBUG oslo.privsep.daemon [-] privsep: request[140502267199568]: (3, 'neutron.privileged.agent.linux.ip_lib.list_netns', (), {}) loop /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:443 2020-03-28 05:16:11.140 4048 DEBUG oslo.privsep.daemon [-] privsep: reply[140502267199568]: (4, ['qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df']) loop /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:456 2020-03-28 05:16:11.142 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'link', 'set', 'tap01d47a8b-5a', 'netns', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:11.165 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip', 'link', 'set', 'tap01d47a8b-5a', 'mtu', '1350'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:11.255 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip', 'link', 'set', 'tap01d47a8b-5a', 'up'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:11.292 29199 DEBUG oslo_concurrency.lockutils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Acquired semaphore "iptables-qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:212 2020-03-28 05:16:11.294 29199 DEBUG oslo_concurrency.lockutils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Acquired external semaphore "iptables-qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:219 2020-03-28 05:16:11.295 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'iptables-save'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:11.329 29199 DEBUG neutron.agent.linux.iptables_manager [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Unable to find table mangle _find_table /usr/lib/python2.7/site-packages/neutron/agent/linux/iptables_manager.py:634 2020-03-28 05:16:11.331 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'iptables-restore', '-n'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:11.396 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip6tables-save'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:11.416 29199 DEBUG neutron.agent.linux.iptables_manager [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Unable to find table mangle _find_table /usr/lib/python2.7/site-packages/neutron/agent/linux/iptables_manager.py:634 2020-03-28 05:16:11.416 29199 DEBUG neutron.agent.linux.iptables_manager [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Unable to find table raw _find_table /usr/lib/python2.7/site-packages/neutron/agent/linux/iptables_manager.py:634 2020-03-28 05:16:11.417 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip6tables-restore', '-n'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:11.451 29199 DEBUG neutron.agent.linux.iptables_manager [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] IPTablesManager.apply completed with success. 106 iptables commands were issued _apply_synchronized /usr/lib/python2.7/site-packages/neutron/agent/linux/iptables_manager.py:623 2020-03-28 05:16:11.452 29199 DEBUG oslo_concurrency.lockutils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Releasing semaphore "iptables-qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df" lock /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:228 2020-03-28 05:16:11.453 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip', '-o', 'link', 'show', 'tap01d47a8b-5a'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:11.483 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip', 'addr', 'show', 'tap01d47a8b-5a'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:11.511 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip', '-4', 'addr', 'add', '192.168.24.5/24', 'scope', 'global', 'dev', 'tap01d47a8b-5a', 'brd', '192.168.24.255'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:11.542 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip', '-4', 'route', 'list', 'dev', 'tap01d47a8b-5a'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:11.568 29199 DEBUG neutron.agent.linux.dhcp [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Setting IPv4 gateway for dhcp netns on net ab116a3d-4224-46e2-8085-6e8a116510df to 192.168.24.1 _set_default_route_ip_version /usr/lib/python2.7/site-packages/neutron/agent/linux/dhcp.py:1268 2020-03-28 05:16:11.569 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip', '-4', 'route', 'replace', 'default', 'via', '192.168.24.1', 'dev', 'tap01d47a8b-5a'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:11.592 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip', '-6', 'route', 'list', 'dev', 'tap01d47a8b-5a'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:11.613 29199 DEBUG neutron.agent.linux.dhcp [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Cleaning stale devices for network ab116a3d-4224-46e2-8085-6e8a116510df _cleanup_stale_devices /usr/lib/python2.7/site-packages/neutron/agent/linux/dhcp.py:1466 2020-03-28 05:16:11.614 4048 DEBUG oslo.privsep.daemon [-] privsep: request[140502267199568]: (3, 'neutron.privileged.agent.linux.ip_lib.list_netns', (), {}) loop /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:443 2020-03-28 05:16:11.615 4048 DEBUG oslo.privsep.daemon [-] privsep: reply[140502267199568]: (4, ['qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df']) loop /usr/lib/python2.7/site-packages/oslo_privsep/daemon.py:456 2020-03-28 05:16:11.616 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'find', '/sys/class/net', '-maxdepth', '1', '-type', 'l', '-printf', '%f '] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:11.639 29199 DEBUG neutron.agent.linux.dhcp [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Building initial lease file: /var/lib/neutron/dhcp/ab116a3d-4224-46e2-8085-6e8a116510df/leases _output_init_lease_file /usr/lib/python2.7/site-packages/neutron/agent/linux/dhcp.py:644 2020-03-28 05:16:11.640 29199 DEBUG neutron.agent.linux.dhcp [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Done building initial lease file /var/lib/neutron/dhcp/ab116a3d-4224-46e2-8085-6e8a116510df/leases with contents: 1585458971 fa:16:3e:2b:00:83 192.168.24.5 * * _output_init_lease_file /usr/lib/python2.7/site-packages/neutron/agent/linux/dhcp.py:671 2020-03-28 05:16:11.641 29199 DEBUG neutron.agent.linux.dhcp [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Building host file: /var/lib/neutron/dhcp/ab116a3d-4224-46e2-8085-6e8a116510df/host _output_hosts_file /usr/lib/python2.7/site-packages/neutron/agent/linux/dhcp.py:702 2020-03-28 05:16:11.642 29199 DEBUG neutron.agent.linux.dhcp [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Done building host file /var/lib/neutron/dhcp/ab116a3d-4224-46e2-8085-6e8a116510df/host _output_hosts_file /usr/lib/python2.7/site-packages/neutron/agent/linux/dhcp.py:743 2020-03-28 05:16:11.644 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Unable to access /var/lib/neutron/dhcp/ab116a3d-4224-46e2-8085-6e8a116510df/pid get_value_from_file /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:250 2020-03-28 05:16:11.646 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'dnsmasq', '--no-hosts', '--no-resolv', '--pid-file=/var/lib/neutron/dhcp/ab116a3d-4224-46e2-8085-6e8a116510df/pid', '--dhcp-hostsfile=/var/lib/neutron/dhcp/ab116a3d-4224-46e2-8085-6e8a116510df/host', '--addn-hosts=/var/lib/neutron/dhcp/ab116a3d-4224-46e2-8085-6e8a116510df/addn_hosts', '--dhcp-optsfile=/var/lib/neutron/dhcp/ab116a3d-4224-46e2-8085-6e8a116510df/opts', '--dhcp-leasefile=/var/lib/neutron/dhcp/ab116a3d-4224-46e2-8085-6e8a116510df/leases', '--dhcp-match=set:ipxe,175', '--local-service', '--bind-dynamic', '--dhcp-range=set:subnet-7b373b05-b9fc-4708-87c7-ebb7cfebc0ca,192.168.24.0,static,255.255.255.0,86400s', '--dhcp-option-force=option:mtu,1350', '--dhcp-lease-max=256', '--conf-file=/etc/dnsmasq-ironic.conf', '--domain=localdomain'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:11.701 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Unable to access /var/lib/neutron/external/pids/ab116a3d-4224-46e2-8085-6e8a116510df.pid get_value_from_file /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:250 2020-03-28 05:16:11.702 29199 DEBUG neutron.agent.linux.utils [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] Unable to access /var/lib/neutron/external/pids/ab116a3d-4224-46e2-8085-6e8a116510df.pid get_value_from_file /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:250 2020-03-28 05:16:11.702 29199 DEBUG neutron.agent.linux.external_process [req-1069eedb-6389-4c2c-9f6a-f3325d58b4b8 - - - - -] No process started for ab116a3d-4224-46e2-8085-6e8a116510df disable /usr/lib/python2.7/site-packages/neutron/agent/linux/external_process.py:118 2020-03-28 05:16:11.734 29199 INFO neutron.agent.dhcp.agent [req-494a3b93-3855-4ee2-8418-29af099d6287 - - - - -] DHCP configuration for ports set([u'01d47a8b-5a85-4e50-9790-3b38d3378565']) is completed 2020-03-28 05:16:11.964 29199 DEBUG neutron.agent.dhcp.agent [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Calling driver for network: ab116a3d-4224-46e2-8085-6e8a116510df action: reload_allocations call_driver /usr/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:135 2020-03-28 05:16:11.966 29199 DEBUG neutron.agent.linux.dhcp [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Building host file: /var/lib/neutron/dhcp/ab116a3d-4224-46e2-8085-6e8a116510df/host _output_hosts_file /usr/lib/python2.7/site-packages/neutron/agent/linux/dhcp.py:702 2020-03-28 05:16:11.967 29199 DEBUG neutron.agent.linux.dhcp [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Done building host file /var/lib/neutron/dhcp/ab116a3d-4224-46e2-8085-6e8a116510df/host _output_hosts_file /usr/lib/python2.7/site-packages/neutron/agent/linux/dhcp.py:743 2020-03-28 05:16:11.972 29199 DEBUG neutron.agent.linux.utils [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Running command (rootwrap daemon): ['kill', '-HUP', '4120'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:11.989 29199 DEBUG neutron.agent.linux.dhcp [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Reloading allocations for network: ab116a3d-4224-46e2-8085-6e8a116510df reload_allocations /usr/lib/python2.7/site-packages/neutron/agent/linux/dhcp.py:532 2020-03-28 05:16:11.990 29199 DEBUG neutron.agent.linux.utils [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip', '-4', 'route', 'list', 'dev', 'tap01d47a8b-5a'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:12.010 29199 DEBUG neutron.agent.linux.utils [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip', '-6', 'route', 'list', 'dev', 'tap01d47a8b-5a'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:12.036 29199 DEBUG neutron.agent.linux.utils [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Unable to access /var/lib/neutron/external/pids/ab116a3d-4224-46e2-8085-6e8a116510df.pid get_value_from_file /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:250 2020-03-28 05:16:12.037 29199 DEBUG neutron.agent.linux.utils [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Unable to access /var/lib/neutron/external/pids/ab116a3d-4224-46e2-8085-6e8a116510df.pid get_value_from_file /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:250 2020-03-28 05:16:12.037 29199 DEBUG neutron.agent.linux.external_process [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] No process started for ab116a3d-4224-46e2-8085-6e8a116510df disable /usr/lib/python2.7/site-packages/neutron/agent/linux/external_process.py:118 2020-03-28 05:16:12.037 29199 INFO neutron.agent.dhcp.agent [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Trigger reload_allocations for port admin_state_up=True, allowed_address_pairs=[], binding:host_id=undercloud.localdomain, binding:profile=, binding:vif_details=, binding:vif_type=unbound, binding:vnic_type=normal, created_at=2020-03-28T05:16:08Z, description=, device_id=dhcp4ffb0b0c-492f-50f3-b91f-5f97b4a206be-ab116a3d-4224-46e2-8085-6e8a116510df, device_owner=network:dhcp, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'7b373b05-b9fc-4708-87c7-ebb7cfebc0ca', u'ip_address': u'192.168.24.5'}], id=01d47a8b-5a85-4e50-9790-3b38d3378565, ip_allocation=immediate, mac_address=fa:16:3e:2b:00:83, name=, network_id=ab116a3d-4224-46e2-8085-6e8a116510df, port_security_enabled=False, project_id=fca02e1b049443179175814c8eeb7b29, revision_number=4, security_groups=[], status=DOWN, tags=[], tenant_id=fca02e1b049443179175814c8eeb7b29, updated_at=2020-03-28T05:16:08Z 2020-03-28 05:16:12.038 29199 DEBUG neutron.agent.dhcp.agent [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Calling driver for network: ab116a3d-4224-46e2-8085-6e8a116510df action: reload_allocations call_driver /usr/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:135 2020-03-28 05:16:12.038 29199 DEBUG neutron.agent.linux.dhcp [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Building host file: /var/lib/neutron/dhcp/ab116a3d-4224-46e2-8085-6e8a116510df/host _output_hosts_file /usr/lib/python2.7/site-packages/neutron/agent/linux/dhcp.py:702 2020-03-28 05:16:12.039 29199 DEBUG neutron.agent.linux.dhcp [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Done building host file /var/lib/neutron/dhcp/ab116a3d-4224-46e2-8085-6e8a116510df/host _output_hosts_file /usr/lib/python2.7/site-packages/neutron/agent/linux/dhcp.py:743 2020-03-28 05:16:12.040 29199 DEBUG neutron.agent.linux.utils [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Running command (rootwrap daemon): ['kill', '-HUP', '4120'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:12.047 29199 DEBUG neutron.agent.linux.dhcp [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Reloading allocations for network: ab116a3d-4224-46e2-8085-6e8a116510df reload_allocations /usr/lib/python2.7/site-packages/neutron/agent/linux/dhcp.py:532 2020-03-28 05:16:12.048 29199 DEBUG neutron.agent.linux.utils [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip', '-4', 'route', 'list', 'dev', 'tap01d47a8b-5a'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:12.073 29199 DEBUG neutron.agent.linux.utils [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip', '-6', 'route', 'list', 'dev', 'tap01d47a8b-5a'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:12.099 29199 DEBUG neutron.agent.linux.utils [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Unable to access /var/lib/neutron/external/pids/ab116a3d-4224-46e2-8085-6e8a116510df.pid get_value_from_file /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:250 2020-03-28 05:16:12.099 29199 DEBUG neutron.agent.linux.utils [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Unable to access /var/lib/neutron/external/pids/ab116a3d-4224-46e2-8085-6e8a116510df.pid get_value_from_file /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:250 2020-03-28 05:16:12.099 29199 DEBUG neutron.agent.linux.external_process [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] No process started for ab116a3d-4224-46e2-8085-6e8a116510df disable /usr/lib/python2.7/site-packages/neutron/agent/linux/external_process.py:118 2020-03-28 05:16:12.100 29199 INFO neutron.agent.dhcp.agent [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Trigger reload_allocations for port admin_state_up=True, allowed_address_pairs=[], binding:host_id=undercloud.localdomain, binding:profile=, binding:vif_details=bridge_name=br-int, datapath_type=system, ovs_hybrid_plug=True, port_filter=True, binding:vif_type=ovs, binding:vnic_type=normal, created_at=2020-03-28T05:16:08Z, description=, device_id=dhcp4ffb0b0c-492f-50f3-b91f-5f97b4a206be-ab116a3d-4224-46e2-8085-6e8a116510df, device_owner=network:dhcp, extra_dhcp_opts=[], fixed_ips=[{u'subnet_id': u'7b373b05-b9fc-4708-87c7-ebb7cfebc0ca', u'ip_address': u'192.168.24.5'}], id=01d47a8b-5a85-4e50-9790-3b38d3378565, ip_allocation=immediate, mac_address=fa:16:3e:2b:00:83, name=, network_id=ab116a3d-4224-46e2-8085-6e8a116510df, port_security_enabled=False, project_id=fca02e1b049443179175814c8eeb7b29, revision_number=5, security_groups=[], status=DOWN, tags=[], tenant_id=fca02e1b049443179175814c8eeb7b29, updated_at=2020-03-28T05:16:08Z 2020-03-28 05:16:12.100 29199 DEBUG neutron.agent.dhcp.agent [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Calling driver for network: ab116a3d-4224-46e2-8085-6e8a116510df action: reload_allocations call_driver /usr/lib/python2.7/site-packages/neutron/agent/dhcp/agent.py:135 2020-03-28 05:16:12.101 29199 DEBUG neutron.agent.linux.dhcp [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Building host file: /var/lib/neutron/dhcp/ab116a3d-4224-46e2-8085-6e8a116510df/host _output_hosts_file /usr/lib/python2.7/site-packages/neutron/agent/linux/dhcp.py:702 2020-03-28 05:16:12.102 29199 DEBUG neutron.agent.linux.dhcp [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Done building host file /var/lib/neutron/dhcp/ab116a3d-4224-46e2-8085-6e8a116510df/host _output_hosts_file /usr/lib/python2.7/site-packages/neutron/agent/linux/dhcp.py:743 2020-03-28 05:16:12.104 29199 DEBUG neutron.agent.linux.utils [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Running command (rootwrap daemon): ['kill', '-HUP', '4120'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:12.110 29199 DEBUG neutron.agent.linux.dhcp [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Reloading allocations for network: ab116a3d-4224-46e2-8085-6e8a116510df reload_allocations /usr/lib/python2.7/site-packages/neutron/agent/linux/dhcp.py:532 2020-03-28 05:16:12.110 29199 DEBUG neutron.agent.linux.utils [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip', '-4', 'route', 'list', 'dev', 'tap01d47a8b-5a'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:12.134 29199 DEBUG neutron.agent.linux.utils [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Running command (rootwrap daemon): ['ip', 'netns', 'exec', 'qdhcp-ab116a3d-4224-46e2-8085-6e8a116510df', 'ip', '-6', 'route', 'list', 'dev', 'tap01d47a8b-5a'] execute_rootwrap_daemon /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:103 2020-03-28 05:16:12.139 29199 INFO neutron.agent.dhcp.agent [req-0043ac7c-756c-456e-a101-43843f8f3951 - - - - -] DHCP configuration for ports set([u'01d47a8b-5a85-4e50-9790-3b38d3378565']) is completed 2020-03-28 05:16:12.157 29199 DEBUG neutron.agent.linux.utils [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Unable to access /var/lib/neutron/external/pids/ab116a3d-4224-46e2-8085-6e8a116510df.pid get_value_from_file /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:250 2020-03-28 05:16:12.158 29199 DEBUG neutron.agent.linux.utils [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] Unable to access /var/lib/neutron/external/pids/ab116a3d-4224-46e2-8085-6e8a116510df.pid get_value_from_file /usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py:250 2020-03-28 05:16:12.158 29199 DEBUG neutron.agent.linux.external_process [req-9e1c0576-7e62-4e4f-9772-085496f5c503 - - - - -] No process started for ab116a3d-4224-46e2-8085-6e8a116510df disable /usr/lib/python2.7/site-packages/neutron/agent/linux/external_process.py:118 2020-03-28 05:16:12.242 29199 INFO neutron.agent.dhcp.agent [req-2d1895d6-c1db-4d01-b925-37f1ce5c290a - - - - -] DHCP configuration for ports set([u'01d47a8b-5a85-4e50-9790-3b38d3378565']) is completed 2020-03-28 05:16:15.526 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" acquired by "neutron.agent.linux.external_process._check_child_processes" :: waited 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273 2020-03-28 05:16:15.527 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" released by "neutron.agent.linux.external_process._check_child_processes" :: held 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285 2020-03-28 05:17:15.529 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" acquired by "neutron.agent.linux.external_process._check_child_processes" :: waited 0.002s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273 2020-03-28 05:17:15.535 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" released by "neutron.agent.linux.external_process._check_child_processes" :: held 0.007s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285 2020-03-28 05:18:15.527 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" acquired by "neutron.agent.linux.external_process._check_child_processes" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273 2020-03-28 05:18:15.532 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" released by "neutron.agent.linux.external_process._check_child_processes" :: held 0.005s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285 2020-03-28 05:19:15.529 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" acquired by "neutron.agent.linux.external_process._check_child_processes" :: waited 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273 2020-03-28 05:19:15.533 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" released by "neutron.agent.linux.external_process._check_child_processes" :: held 0.004s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285 2020-03-28 05:20:15.530 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" acquired by "neutron.agent.linux.external_process._check_child_processes" :: waited 0.001s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273 2020-03-28 05:20:15.535 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" released by "neutron.agent.linux.external_process._check_child_processes" :: held 0.006s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285 2020-03-28 05:21:15.530 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" acquired by "neutron.agent.linux.external_process._check_child_processes" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273 2020-03-28 05:21:15.536 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" released by "neutron.agent.linux.external_process._check_child_processes" :: held 0.007s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285 2020-03-28 05:22:15.530 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" acquired by "neutron.agent.linux.external_process._check_child_processes" :: waited 0.000s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:273 2020-03-28 05:22:15.537 29199 DEBUG oslo_concurrency.lockutils [-] Lock "_check_child_processes" released by "neutron.agent.linux.external_process._check_child_processes" :: held 0.007s inner /usr/lib/python2.7/site-packages/oslo_concurrency/lockutils.py:285