Reviewed: https://review.openstack.org/413010 Committed: https://git.openstack.org/cgit/openstack/neutron/commit/?id=f15851b98974dc16606da195cf3ecee577cd0ef8 Submitter: Jenkins Branch: master
commit f15851b98974dc16606da195cf3ecee577cd0ef8 Author: Bertrand Lallau <[email protected]> Date: Tue Dec 20 10:53:41 2016 +0100 DHCP: enhance DHCPAgent startup procedure During DhcpAgent startup procedure all the following networks initialization is actually perform twice: * Killing old dnsmasq processes * set and configure all TAP interfaces * building all Dnsmasq config files (lease and host files) * launching dnsmasq processes What is done during the second iteration is just clean and redo exactly the same another time! This is really inefficient and increase dramatically DHCP startup time (near twice than needed). Initialization process 'sync_state' method is called twice: * one time during init_host() * another time during _report_state() sync_state() call must stay in init_host() due to bug #1420042. sync_state() is always called during startup in init_host() and will be periodically called by periodic_resync() to do reconciliation. Hence it can safely be removed from the run() method. Change-Id: Id6433598d5c833d2e86be605089d42feee57c257 Closes-bug: #1651368 Closes-Bug: #1650611 ** Changed in: neutron Status: In Progress => Fix Released -- You received this bug notification because you are a member of Yahoo! Engineering Team, which is subscribed to neutron. https://bugs.launchpad.net/bugs/1651368 Title: Dhcpagent not efficient during initialization process Status in neutron: Fix Released Bug description: During DhcpAgent startup procedure all networks initialization will be done twice: * Killing old dnsmasq processes * set and configure all TAP interfaces * building all Dnsmasq config files (lease and host files) * launching dnsmasq processes This is really inefficient and can be strange in case of namespaces monitoring. The following Dhcpagent traces show the actual init process (logs have been cleanup to show only relevant informations) Explanations details are described after logs. 2016-12-20 09:02:42.200 DEBUG neutron.openstack.common.service [req-b0a2772 None None] ******************************************************************************** log_opt_values /usr/lib/python2.7/dist-packages/oslo_config/cfg.py:2197 2016-12-20 09:02:42.214 INFO neutron.agent.dhcp.agent [-] Synchronizing state 2016-12-20 09:02:43.262 DEBUG neutron.agent.dhcp.agent [-] Calling driver for network: 5be9fe58-0790-4342-9182-172438e8e0bc action: enable call_driver /usr/lib/python2.7/dist-packages/neutron/agent/dhcp/agent.py:106 2016-12-20 09:02:43.314 DEBUG neutron.agent.dhcp.agent [-] Calling driver for network: f2a73fc1-6a93-4822-aa45-3333b789d50d action: enable call_driver /usr/lib/python2.7/dist-packages/neutron/agent/dhcp/agent.py:106 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'kill', '-9', '24540'] 2016-12-20 09:02:43.441 DEBUG neutron.agent.linux.utils [-] Unable to access /var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/pid get_value_from_file /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:222 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'kill', '-9', '24542'] 2016-12-20 09:02:43.459 DEBUG neutron.agent.linux.utils [-] Unable to access /var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/pid get_value_from_file /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:222 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-5be9fe58-0790-4342-9182-172438e8e0bc', 'ip', 'link', 'set', 'tap5c7f794d-08', 'up'] Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-f2a73fc1-6a93-4822-aa45-3333b789d50d', 'ip', 'link', 'set', 'tap995da463-09', 'up'] Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-5be9fe58-0790-4342-9182-172438e8e0bc', 'ip', 'addr', 'show', 'tap5c7f794d-08', 'permanent', 'scope', 'global'] Stdout: 32: tap5c7f794d-08: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UNKNOWN group default link/ether fa:16:3e:6b:cb:29 brd ff:ff:ff:ff:ff:ff inet 20.0.0.36/24 brd 20.0.0.255 scope global tap5c7f794d-08 valid_lft forever preferred_lft forever inet 169.254.169.254/16 brd 169.254.255.255 scope global tap5c7f794d-08 valid_lft forever preferred_lft forever Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-f2a73fc1-6a93-4822-aa45-3333b789d50d', 'ip', 'addr', 'show', 'tap995da463-09', 'permanent', 'scope', 'global'] Stdout: 35: tap995da463-09: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UNKNOWN group default link/ether fa:16:3e:49:6e:68 brd ff:ff:ff:ff:ff:ff inet 20.0.1.36/24 brd 20.0.1.255 scope global tap995da463-09 valid_lft forever preferred_lft forever inet 169.254.169.254/16 brd 169.254.255.255 scope global tap995da463-09 valid_lft forever preferred_lft forever Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-f2a73fc1-6a93-4822-aa45-3333b789d50d', 'ip', '-4', 'route', 'list', 'dev', 'tap995da463-09', 'scope', 'link'] Stdout: 20.0.1.0/24 proto kernel src 20.0.1.36 169.254.0.0/16 proto kernel src 169.254.169.254 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-5be9fe58-0790-4342-9182-172438e8e0bc', 'ip', '-4', 'route', 'list', 'dev', 'tap5c7f794d-08', 'scope', 'link'] Stdout: 20.0.0.0/24 proto kernel src 20.0.0.36 169.254.0.0/16 proto kernel src 169.254.169.254 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-f2a73fc1-6a93-4822-aa45-3333b789d50d', 'ip', '-6', 'route', 'list', 'dev', 'tap995da463-09', 'scope', 'link'] Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-5be9fe58-0790-4342-9182-172438e8e0bc', 'ip', '-6', 'route', 'list', 'dev', 'tap5c7f794d-08', 'scope', 'link'] Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-f2a73fc1-6a93-4822-aa45-3333b789d50d', 'ip', 'route', 'list', 'dev', 'tap995da463-09'] Stdout: 20.0.1.0/24 proto kernel scope link src 20.0.1.36 169.254.0.0/16 proto kernel scope link src 169.254.169.254 2016-12-20 09:02:44.154 DEBUG neutron.agent.linux.dhcp [-] Building initial lease file: /var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/leases _output_init_lease_file /home/T0125936/work/curr/neutron/neutron/agent/linux/dhcp.py:480 2016-12-20 09:02:44.155 DEBUG neutron.agent.linux.dhcp [-] Done building initial lease file /var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/leases with contents: 1482310964 fa:16:3e:49:6e:68 20.0.1.36 * * 1482310964 fa:16:3e:81:6c:f3 20.0.1.35 * * _output_init_lease_file /home/T0125936/work/curr/neutron/neutron/agent/linux/dhcp.py:507 2016-12-20 09:02:44.156 DEBUG neutron.agent.linux.dhcp [-] Building host file: /var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/host _output_hosts_file neutron/agent/linux/dhcp.py:538 2016-12-20 09:02:44.156 DEBUG neutron.agent.linux.dhcp [-] Done building host file /var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/host with contents: fa:16:3e:49:6e:68,host-20-0-1-36.openstacklocal,20.0.1.36 fa:16:3e:81:6c:f3,host-20-0-1-35.openstacklocal,20.0.1.35 _output_hosts_file neutron/agent/linux/dhcp.py:567 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-5be9fe58-0790-4342-9182-172438e8e0bc', 'ip', 'route', 'list', 'dev', 'tap5c7f794d-08'] Stdout: 20.0.0.0/24 proto kernel scope link src 20.0.0.36 169.254.0.0/16 proto kernel scope link src 169.254.169.254 Stderr: execute /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:134 2016-12-20 09:02:44.173 DEBUG neutron.agent.linux.dhcp [-] Building initial lease file: /var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/leases _output_init_lease_file neutron/agent/linux/dhcp.py:480 2016-12-20 09:02:44.173 DEBUG neutron.agent.linux.dhcp [-] Done building initial lease file /var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/leases with contents: 1482310964 fa:16:3e:6b:cb:29 20.0.0.36 * * 1482310964 fa:16:3e:74:32:29 20.0.0.35 * * _output_init_lease_file neutron/agent/linux/dhcp.py:507 2016-12-20 09:02:44.174 DEBUG neutron.agent.linux.dhcp [-] Building host file: /var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/host _output_hosts_file neutron/agent/linux/dhcp.py:538 2016-12-20 09:02:44.175 DEBUG neutron.agent.linux.dhcp [-] Done building host file /var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/host with contents: fa:16:3e:6b:cb:29,host-20-0-0-36.openstacklocal,20.0.0.36 fa:16:3e:74:32:29,host-20-0-0-35.openstacklocal,20.0.0.35 _output_hosts_file neutron/agent/linux/dhcp.py:567 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-f2a73fc1-6a93-4822-aa45-3333b789d50d', 'ip', 'addr', 'show', 'tap995da463-09'] Stdout: 35: tap995da463-09: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UNKNOWN group default link/ether fa:16:3e:49:6e:68 brd ff:ff:ff:ff:ff:ff inet 20.0.1.36/24 brd 20.0.1.255 scope global tap995da463-09 valid_lft forever preferred_lft forever inet 169.254.169.254/16 brd 169.254.255.255 scope global tap995da463-09 valid_lft forever preferred_lft forever inet6 fe80::f816:3eff:fe49:6e68/64 scope link valid_lft forever preferred_lft forever Stderr: execute /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:134 2016-12-20 09:02:44.293 DEBUG neutron.agent.linux.utils [-] Unable to access /var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/pid get_value_from_file /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:222 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-5be9fe58-0790-4342-9182-172438e8e0bc', 'ip', 'addr', 'show', 'tap5c7f794d-08'] Stdout: 32: tap5c7f794d-08: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UNKNOWN group default link/ether fa:16:3e:6b:cb:29 brd ff:ff:ff:ff:ff:ff inet 20.0.0.36/24 brd 20.0.0.255 scope global tap5c7f794d-08 valid_lft forever preferred_lft forever inet 169.254.169.254/16 brd 169.254.255.255 scope global tap5c7f794d-08 valid_lft forever preferred_lft forever inet6 fe80::f816:3eff:fe6b:cb29/64 scope link valid_lft forever preferred_lft forever Stderr: execute /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:134 2016-12-20 09:02:44.313 DEBUG neutron.agent.linux.utils [-] Unable to access /var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/pid get_value_from_file /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:222 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-f2a73fc1-6a93-4822-aa45-3333b789d50d', 'dnsmasq', '--no-hosts', '--no-resolv', '--strict-order', '--bind-interfaces', '--interface=tap995da463-09', '--except-interface=lo', '--pid-file=/var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/pid', '--dhcp-hostsfile=/var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/host', '--addn-hosts=/var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/addn_hosts', '--dhcp-optsfile=/var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/opts', '--dhcp-leasefile=/var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/leases', '--dhcp-range=set:tag0,20.0.1.0,static,86400s', '--dhcp-lease-max=256', '--conf-file=/etc/neutron/dnsmasq.conf', '--domain=openstacklocal'] Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-5be9fe58-0790-4342-9182-172438e8e0bc', 'dnsmasq', '--no-hosts', '--no-resolv', '--strict-order', '--bind-interfaces', '--interface=tap5c7f794d-08', '--except-interface=lo', '--pid-file=/var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/pid', '--dhcp-hostsfile=/var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/host', '--addn-hosts=/var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/addn_hosts', '--dhcp-optsfile=/var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/opts', '--dhcp-leasefile=/var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/leases', '--dhcp-range=set:tag0,20.0.0.0,static,86400s', '--dhcp-lease-max=256', '--conf-file=/etc/neutron/dnsmasq.conf', '--domain=openstacklocal'] 2016-12-20 09:02:44.441 INFO neutron.agent.dhcp.agent [-] Synchronizing state complete 2016-12-20 09:02:44.453 DEBUG oslo_concurrency.lockutils [req-555b9ae None None] Lock "dhcp-agent" acquired by "sync_state" :: waited 2.081s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:444 2016-12-20 09:02:44.453 INFO neutron.agent.dhcp.agent [req-555b9ae None None] Synchronizing state 2016-12-20 09:02:44.479 INFO neutron.agent.dhcp.agent [-] DHCP agent started 2016-12-20 09:02:44.696 DEBUG neutron.agent.dhcp.agent [-] Calling driver for network: 5be9fe58-0790-4342-9182-172438e8e0bc action: enable call_driver /usr/lib/python2.7/dist-packages/neutron/agent/dhcp/agent.py:106 2016-12-20 09:02:44.704 DEBUG neutron.agent.dhcp.agent [-] Calling driver for network: f2a73fc1-6a93-4822-aa45-3333b789d50d action: enable call_driver /usr/lib/python2.7/dist-packages/neutron/agent/dhcp/agent.py:106 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'kill', '-9', '24936'] 2016-12-20 09:02:44.820 DEBUG neutron.agent.linux.utils [-] Unable to access /var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/pid get_value_from_file /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:222 2016-12-20 09:02:44.836 DEBUG neutron.agent.linux.utils [-] Unable to access /var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/pid get_value_from_file /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:222 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-5be9fe58-0790-4342-9182-172438e8e0bc', 'ip', 'link', 'set', 'tap5c7f794d-08', 'up'] 2016-12-20 09:02:45.126 DEBUG neutron.agent.linux.dhcp [-] Reusing existing device: tap5c7f794d-08. setup neutron/agent/linux/dhcp.py:1009 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-f2a73fc1-6a93-4822-aa45-3333b789d50d', 'ip', 'link', 'set', 'tap995da463-09', 'up'] 2016-12-20 09:02:45.192 DEBUG neutron.agent.linux.dhcp [-] Reusing existing device: tap995da463-09. setup neutron/agent/linux/dhcp.py:1009 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-5be9fe58-0790-4342-9182-172438e8e0bc', 'ip', 'addr', 'show', 'tap5c7f794d-08', 'permanent', 'scope', 'global'] Stdout: 32: tap5c7f794d-08: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UNKNOWN group default link/ether fa:16:3e:6b:cb:29 brd ff:ff:ff:ff:ff:ff inet 20.0.0.36/24 brd 20.0.0.255 scope global tap5c7f794d-08 valid_lft forever preferred_lft forever inet 169.254.169.254/16 brd 169.254.255.255 scope global tap5c7f794d-08 valid_lft forever preferred_lft forever Stderr: execute /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:134 2016-12-20 09:02:45.386 DEBUG neutron.agent.linux.utils [-] Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-f2a73fc1-6a93-4822-aa45-3333b789d50d', 'ip', 'addr', 'show', 'tap995da463-09', 'permanent', 'scope', 'global'] Stdout: 35: tap995da463-09: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UNKNOWN group default link/ether fa:16:3e:49:6e:68 brd ff:ff:ff:ff:ff:ff inet 20.0.1.36/24 brd 20.0.1.255 scope global tap995da463-09 valid_lft forever preferred_lft forever inet 169.254.169.254/16 brd 169.254.255.255 scope global tap995da463-09 valid_lft forever preferred_lft forever Stderr: execute /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:134 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-5be9fe58-0790-4342-9182-172438e8e0bc', 'ip', '-4', 'route', 'list', 'dev', 'tap5c7f794d-08', 'scope', 'link'] Stdout: 20.0.0.0/24 proto kernel src 20.0.0.36 169.254.0.0/16 proto kernel src 169.254.169.254 Stderr: execute /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:134 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-f2a73fc1-6a93-4822-aa45-3333b789d50d', 'ip', '-4', 'route', 'list', 'dev', 'tap995da463-09', 'scope', 'link'] Stdout: 20.0.1.0/24 proto kernel src 20.0.1.36 169.254.0.0/16 proto kernel src 169.254.169.254 Stderr: execute /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:134 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-5be9fe58-0790-4342-9182-172438e8e0bc', 'ip', '-6', 'route', 'list', 'dev', 'tap5c7f794d-08', 'scope', 'link'] Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-f2a73fc1-6a93-4822-aa45-3333b789d50d', 'ip', '-6', 'route', 'list', 'dev', 'tap995da463-09', 'scope', 'link'] Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-5be9fe58-0790-4342-9182-172438e8e0bc', 'ip', 'route', 'list', 'dev', 'tap5c7f794d-08'] Stdout: 20.0.0.0/24 proto kernel scope link src 20.0.0.36 169.254.0.0/16 proto kernel scope link src 169.254.169.254 Stderr: execute /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:134 2016-12-20 09:02:45.862 DEBUG neutron.agent.linux.dhcp [-] Building initial lease file: /var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/leases _output_init_lease_file neutron/agent/linux/dhcp.py:480 2016-12-20 09:02:45.863 DEBUG neutron.agent.linux.dhcp [-] Done building initial lease file /var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/leases with contents: 1482310965 fa:16:3e:6b:cb:29 20.0.0.36 * * 1482310965 fa:16:3e:74:32:29 20.0.0.35 * * _output_init_lease_file neutron/agent/linux/dhcp.py:507 2016-12-20 09:02:45.865 DEBUG neutron.agent.linux.dhcp [-] Building host file: /var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/host _output_hosts_file neutron/agent/linux/dhcp.py:538 2016-12-20 09:02:45.874 DEBUG neutron.agent.linux.dhcp [-] Done building host file /var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/host with contents: fa:16:3e:6b:cb:29,host-20-0-0-36.openstacklocal,20.0.0.36 fa:16:3e:74:32:29,host-20-0-0-35.openstacklocal,20.0.0.35 _output_hosts_file neutron/agent/linux/dhcp.py:567 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-f2a73fc1-6a93-4822-aa45-3333b789d50d', 'ip', 'route', 'list', 'dev', 'tap995da463-09'] Exit code: 0 Stdin: Stdout: 20.0.1.0/24 proto kernel scope link src 20.0.1.36 169.254.0.0/16 proto kernel scope link src 169.254.169.254 Stderr: execute /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:134 2016-12-20 09:02:45.971 DEBUG neutron.agent.linux.dhcp [-] Building initial lease file: /var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/leases _output_init_lease_file neutron/agent/linux/dhcp.py:480 2016-12-20 09:02:45.977 DEBUG neutron.agent.linux.dhcp [-] Done building initial lease file /var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/leases with contents: 1482310965 fa:16:3e:49:6e:68 20.0.1.36 * * 1482310965 fa:16:3e:81:6c:f3 20.0.1.35 * * _output_init_lease_file neutron/agent/linux/dhcp.py:507 2016-12-20 09:02:45.978 DEBUG neutron.agent.linux.dhcp [-] Building host file: /var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/host _output_hosts_file neutron/agent/linux/dhcp.py:538 2016-12-20 09:02:45.986 DEBUG neutron.agent.linux.dhcp [-] Done building host file /var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/host with contents: fa:16:3e:49:6e:68,host-20-0-1-36.openstacklocal,20.0.1.36 fa:16:3e:81:6c:f3,host-20-0-1-35.openstacklocal,20.0.1.35 _output_hosts_file neutron/agent/linux/dhcp.py:567 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-5be9fe58-0790-4342-9182-172438e8e0bc', 'ip', 'addr', 'show', 'tap5c7f794d-08'] Stdout: 32: tap5c7f794d-08: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UNKNOWN group default link/ether fa:16:3e:6b:cb:29 brd ff:ff:ff:ff:ff:ff inet 20.0.0.36/24 brd 20.0.0.255 scope global tap5c7f794d-08 valid_lft forever preferred_lft forever inet 169.254.169.254/16 brd 169.254.255.255 scope global tap5c7f794d-08 valid_lft forever preferred_lft forever inet6 fe80::f816:3eff:fe6b:cb29/64 scope link valid_lft forever preferred_lft forever Stderr: execute /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:134 2016-12-20 09:02:46.107 DEBUG neutron.agent.linux.utils [-] Unable to access /var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/pid get_value_from_file /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:222 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-f2a73fc1-6a93-4822-aa45-3333b789d50d', 'ip', 'addr', 'show', 'tap995da463-09'] Stdout: 35: tap995da463-09: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UNKNOWN group default link/ether fa:16:3e:49:6e:68 brd ff:ff:ff:ff:ff:ff inet 20.0.1.36/24 brd 20.0.1.255 scope global tap995da463-09 valid_lft forever preferred_lft forever inet 169.254.169.254/16 brd 169.254.255.255 scope global tap995da463-09 valid_lft forever preferred_lft forever inet6 fe80::f816:3eff:fe49:6e68/64 scope link valid_lft forever preferred_lft forever Stderr: execute /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:134 2016-12-20 09:02:46.259 DEBUG neutron.agent.linux.utils [-] Unable to access /var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/pid get_value_from_file /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:222 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-5be9fe58-0790-4342-9182-172438e8e0bc', 'dnsmasq', '--no-hosts', '--no-resolv', '--strict-order', '--bind-interfaces', '--interface=tap5c7f794d-08', '--except-interface=lo', '--pid-file=/var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/pid', '--dhcp-hostsfile=/var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/host', '--addn-hosts=/var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/addn_hosts', '--dhcp-optsfile=/var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/opts', '--dhcp-leasefile=/var/lib/neutron/dhcp/5be9fe58-0790-4342-9182-172438e8e0bc/leases', '--dhcp-range=set:tag0,20.0.0.0,static,86400s', '--dhcp-lease-max=256', '--conf-file=/etc/neutron/dnsmasq.conf', '--domain=openstacklocal'] Stderr: execute /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:134 Command: ['sudo', '/usr/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qdhcp-f2a73fc1-6a93-4822-aa45-3333b789d50d', 'dnsmasq', '--no-hosts', '--no-resolv', '--strict-order', '--bind-interfaces', '--interface=tap995da463-09', '--except-interface=lo', '--pid-file=/var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/pid', '--dhcp-hostsfile=/var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/host', '--addn-hosts=/var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/addn_hosts', '--dhcp-optsfile=/var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/opts', '--dhcp-leasefile=/var/lib/neutron/dhcp/f2a73fc1-6a93-4822-aa45-3333b789d50d/leases', '--dhcp-range=set:tag0,20.0.1.0,static,86400s', '--dhcp-lease-max=256', '--conf-file=/etc/neutron/dnsmasq.conf', '--domain=openstacklocal'] Stderr: execute /usr/lib/python2.7/dist-packages/neutron/agent/linux/utils.py:134 2016-12-20 09:02:46.483 INFO neutron.agent.dhcp.agent [req-555b9ae None None] Synchronizing state complete 2016-12-20 09:02:46.483 DEBUG oslo_concurrency.lockutils [req-555b9ae None None] Lock "dhcp-agent" released by "sync_state" :: held 2.031s inner /usr/lib/python2.7/dist-packages/oslo_concurrency/lockutils.py:456 ***************** Explanations ***************** 09:02:42.200: Dhcpagent config is loaded 09:02:42.214: FIRST networks initialization BEGIN 09:02:43.441: killing dnsmasq processes 09:02:43.459 - 09:02:44.154: TAP interfaces configuration 09:02:44.154 - 09:02:44.175: building dnsmasq files 09:02:44.313 - 09:02:44.441: launching dnsmasq processes 09:02:44.441: FIRST networks initialization END 09:02:44.453: SECOND networks initialization BEGIN 09:02:44.704: killing DNSMASQ processes 09:02:44.836 - 09:02:45.862: TAP interfaces configuration 09:02:45.862 - 09:02:46.107: building dnsmasq files 09:02:46.259 - 09:02:46.483: launching dnsmasq processes 09:02:46.483: SECOND networks initialization END To manage notifications about this bug go to: https://bugs.launchpad.net/neutron/+bug/1651368/+subscriptions -- Mailing list: https://launchpad.net/~yahoo-eng-team Post to : [email protected] Unsubscribe : https://launchpad.net/~yahoo-eng-team More help : https://help.launchpad.net/ListHelp
