Public bug reported:
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 procedure describe just above (logs
have been cleanup to show only relevant informations)
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: configuration TAP interface
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: configuration TAP interface
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
** Affects: neutron
Importance: Undecided
Assignee: Bertrand Lallau (bertrand-lallau)
Status: New
** Changed in: neutron
Assignee: (unassigned) => Bertrand Lallau (bertrand-lallau)
--
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:
New
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 procedure describe just above (logs
have been cleanup to show only relevant informations)
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: configuration TAP interface
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: configuration TAP interface
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
