← Back to team overview

yahoo-eng-team team mailing list archive

  1. yahoo-eng-team team
  2. Mailing list archive
  3. Message #35558

[Bug 1477030] [NEW] VPNaas: rdo-kilo: restarting vpn agent with active tunnels, will not bring up exisiting tunnels

  Thread Previous • Date Previous • • Thread Next 
Public bug reported:

rdo-kilo vpnaas on centos71

1. With existing tunnels, if vpn agent is restarted, the tunnels will
not come up...

2. 
[root@ceos71 ~(keystone_admin)]# neutron  vpn-service-list
+--------------------------------------+------+--------------------------------------+--------+
| id                                   | name | router_id                            | status |
+--------------------------------------+------+--------------------------------------+--------+
| 67189109-76cf-493d-9c20-3bf430068d8d | vpn2 | 21f9a7a4-2a3b-48aa-9e4c-88540255cb63 | ACTIVE |
| c0e27fe8-552c-440f-8eaa-709c3ee01b18 | vpn1 | 70e88c46-c6b2-4c8d-afad-76ebd77b55cb | ACTIVE |
+--------------------------------------+------+--------------------------------------+--------+
[root@ceos71 ~(keystone_admin)]# neutron  ipsec-site-connection-list
+--------------------------------------+-------+-----------------+-----------------+------------+-----------+----------------+
| id                                   | name  | peer_address    | peer_cidrs      | route_mode | auth_mode | status         |
+--------------------------------------+-------+-----------------+-----------------+------------+-----------+----------------+
| 89931e0f-6e8a-4e8a-8063-5aa974d70288 | 1vpn1 | 192.168.122.203 | "20.20.20.0/24" | static     | psk       | PENDING_CREATE |
| d16db820-fced-4e00-b750-a25a7d2b7a56 | 1vpn2 | 192.168.122.202 | "10.10.10.0/24" | static     | psk       | PENDING_CREATE |
+--------------------------------------+-------+-----------------+-----------------+------------+-----------+----------------+

3. traffic going fine and tunnels are up
[root@ceos71 ~(keystone_admin)]# /bin/neutron-rootwrap /etc/neutron/rootwrap.conf ip netns exec qrouter-70e88c46-c6b2-4c8d-afad-76ebd77b55cb ipsec whack --ctlbase /var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/var/run/pluto --trafficstatus
000  
006 #2: "89931e0f-6e8a-4e8a-8063-5aa974d70288/0x1", type=ESP,  add_time=1437555102, inBytes=0, outBytes=0
006 #4: "89931e0f-6e8a-4e8a-8063-5aa974d70288/0x1", type=ESP,  add_time=1437555123, inBytes=45140, outBytes=36112
000  
[root@ceos71 ~(keystone_admin)]# 
[root@ceos71 ~(keystone_admin)]# 
[root@ceos71 ~(keystone_admin)]# /bin/neutron-rootwrap /etc/neutron/rootwrap.conf ip netns exec qrouter-21f9a7a4-2a3b-48aa-9e4c-88540255cb63 ipsec whack --ctlbase /var/lib/neutron/ipsec/21f9a7a4-2a3b-48aa-9e4c-88540255cb63/var/run/pluto --trafficstatus
000  
006 #2: "d16db820-fced-4e00-b750-a25a7d2b7a56/0x1", type=ESP,  add_time=1437555123, inBytes=36112, outBytes=45140
000  
[root@ceos71 ~(keystone_admin)]# 

4. [root@ceos71 ~(keystone_admin)]#  service neutron-vpn-agent restart
Redirecting to /bin/systemctl restart  neutron-vpn-agent.service
[root@ceos71 ~(keystone_admin)]# 

5. [root@ceos71 ~(keystone_admin)]# /bin/neutron-rootwrap /etc/neutron/rootwrap.conf ip netns exec qrouter-21f9a7a4-2a3b-48aa-9e4c-88540255cb63 ipsec whack --ctlbase /var/lib/neutron/ipsec/21f9a7a4-2a3b-48aa-9e4c-88540255cb63/var/run/pluto --trafficstatus
whack: is Pluto running?  connect() for "/var/lib/neutron/ipsec/21f9a7a4-2a3b-48aa-9e4c-88540255cb63/var/run/pluto.ctl" failed (111 Connection refused)
[root@ceos71 ~(keystone_admin)]# 
[root@ceos71 ~(keystone_admin)]# 
[root@ceos71 ~(keystone_admin)]# 
[root@ceos71 ~(keystone_admin)]# /bin/neutron-rootwrap /etc/neutron/rootwrap.conf ip netns exec qrouter-70e88c46-c6b2-4c8d-afad-76ebd77b55cb ipsec whack --ctlbase /var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/var/run/pluto --trafficstatus
whack: is Pluto running?  connect() for "/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/var/run/pluto.ctl" failed (111 Connection refused)
[root@ceos71 ~(keystone_admin)]# 

==========
vpn agnet logs, when vpn agent is restarted


2015-07-22 14:27:27.792 7946 INFO neutron.openstack.common.service [req-6defd1a3-dd67-4831-9062-65b7515f02f6 ] Caught SIGTERM, exiting
2015-07-22 14:27:27.945 7946 ERROR oslo_messaging._drivers.impl_rabbit [-] Failed to consume message from queue:
2015-07-22 14:27:28.994 9532 INFO neutron.common.config [-] Logging enabled!
2015-07-22 14:27:28.994 9532 INFO neutron.common.config [-] /usr/bin/neutron-vpn-agent version 2015.1.0
2015-07-22 14:27:28.995 9532 WARNING oslo_config.cfg [-] Option "use_namespaces" from group "DEFAULT" is deprecated for removal.  Its value may be silently ignored in the future.
2015-07-22 14:27:29.014 9532 INFO oslo_messaging._drivers.impl_rabbit [req-d12bbe5c-ea44-4e2f-9627-f3675e6fa6cf ] Connecting to AMQP server on 192.168.122.30:5672
2015-07-22 14:27:29.030 9532 INFO oslo_messaging._drivers.impl_rabbit [req-d12bbe5c-ea44-4e2f-9627-f3675e6fa6cf ] Connected to AMQP server on 192.168.122.30:5672
2015-07-22 14:27:29.037 9532 INFO oslo_messaging._drivers.impl_rabbit [req-d12bbe5c-ea44-4e2f-9627-f3675e6fa6cf ] Connecting to AMQP server on 192.168.122.30:5672
2015-07-22 14:27:29.053 9532 INFO oslo_messaging._drivers.impl_rabbit [req-d12bbe5c-ea44-4e2f-9627-f3675e6fa6cf ] Connected to AMQP server on 192.168.122.30:5672
2015-07-22 14:27:29.092 9532 WARNING neutron.services.provider_configuration [req-d12bbe5c-ea44-4e2f-9627-f3675e6fa6cf ] The configured driver neutron.services.firewall.drivers.linux.iptables_fwaas.IptablesFwaasDriver has been moved, automatically using neutron_fwaas.services.firewall.drivers.linux.iptables_fwaas.IptablesFwaasDriver instead. Please update your config files, as this automatic fixup will be removed in a future release.
2015-07-22 14:27:29.101 9532 INFO oslo_messaging._drivers.impl_rabbit [req-58dc3919-9ee5-419b-aa72-99beda2bb3f6 ] Connecting to AMQP server on 192.168.122.30:5672
2015-07-22 14:27:29.147 9532 INFO eventlet.wsgi.server [-] (9532) wsgi starting up on http:///:v/
2015-07-22 14:27:29.151 9532 INFO oslo_messaging._drivers.impl_rabbit [req-58dc3919-9ee5-419b-aa72-99beda2bb3f6 ] Connected to AMQP server on 192.168.122.30:5672
2015-07-22 14:27:29.170 9532 WARNING oslo_config.cfg [req-58dc3919-9ee5-419b-aa72-99beda2bb3f6 ] Option "nova_region_name" from group "DEFAULT" is deprecated. Use option "region_name" from group "nova".
2015-07-22 14:27:29.172 9532 INFO oslo_messaging._drivers.impl_rabbit [-] Connecting to AMQP server on 192.168.122.30:5672
2015-07-22 14:27:29.188 9532 INFO oslo_messaging._drivers.impl_rabbit [-] Connected to AMQP server on 192.168.122.30:5672
2015-07-22 14:27:29.197 9532 INFO neutron.agent.l3.agent [-] L3 agent started
2015-07-22 14:27:29.628 9532 INFO oslo_messaging._drivers.impl_rabbit [-] Connecting to AMQP server on 192.168.122.30:5672
2015-07-22 14:27:29.188 9532 INFO oslo_messaging._drivers.impl_rabbit [-] Connected to AMQP server on 192.168.122.30:5672
2015-07-22 14:27:29.197 9532 INFO neutron.agent.l3.agent [-] L3 agent started
2015-07-22 14:27:29.628 9532 INFO oslo_messaging._drivers.impl_rabbit [-] Connecting to AMQP server on 192.168.122.30:5672
2015-07-22 14:27:29.641 9532 INFO oslo_messaging._drivers.impl_rabbit [-] Connecting to AMQP server on 192.168.122.30:5672
2015-07-22 14:27:29.668 9532 INFO oslo_messaging._drivers.impl_rabbit [-] Connected to AMQP server on 192.168.122.30:5672
2015-07-22 14:27:29.669 9532 INFO oslo_messaging._drivers.impl_rabbit [-] Connected to AMQP server on 192.168.122.30:5672
2015-07-22 14:27:29.750 9532 INFO neutron.callbacks.manager [-] Notify callbacks for router, before_create
2015-07-22 14:27:29.769 9532 INFO neutron.callbacks.manager [-] Notify callbacks for router, before_create
2015-07-22 14:27:29.786 9532 INFO neutron.callbacks.manager [-] Notify callbacks for router, before_create
2015-07-22 14:27:31.116 9532 INFO neutron.callbacks.manager [req-80912c4c-e33c-4fd2-9ab1-1adc55232a83 ] Notify callbacks for router, after_create
2015-07-22 14:27:31.117 9532 INFO neutron.callbacks.manager [req-80912c4c-e33c-4fd2-9ab1-1adc55232a83 ] Calling callback neutron_vpnaas.services.vpn.vpn_service.router_added_actions
2015-07-22 14:27:31.331 9532 ERROR neutron.agent.linux.utils [req-80912c4c-e33c-4fd2-9ab1-1adc55232a83 ]
Command: ['ipsec', '_stackmanager', 'start']
Exit code: 4
Stdin:
Stdout:
Stderr: permission denied (must be superuser)

2015-07-22 14:27:31.332 9532 ERROR neutron_vpnaas.services.vpn.device_drivers.ipsec [req-80912c4c-e33c-4fd2-9ab1-1adc55232a83 ] Failed to enable vpn process on router 21f9a7a4-2a3b-48aa-9e4c-88540255cb63
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Traceback (most recent call last):
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 251, in enable
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self.ensure_configs()
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/libreswan_ipsec.py", line 31, in ensure_configs
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self._execute([self.binary, '_stackmanager', 'start'])
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 335, in _execute
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes)
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/ip_lib.py", line 580, in execute
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes, **kwargs)
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py", line 137, in execute
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     raise RuntimeError(m)
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec RuntimeError:
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Command: ['ipsec', '_stackmanager', 'start']
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Exit code: 4
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdin:
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdout:
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stderr: permission denied (must be superuser)
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
2015-07-22 14:27:31.349 9532 ERROR neutron.agent.linux.utils [req-80912c4c-e33c-4fd2-9ab1-1adc55232a83 ]
Command: ['ipsec', '_stackmanager', 'start']
Exit code: 4
Stdin:
Stdout:
Stderr: permission denied (must be superuser)

2015-07-22 14:27:31.350 9532 ERROR neutron_vpnaas.services.vpn.device_drivers.ipsec [req-80912c4c-e33c-4fd2-9ab1-1adc55232a83 ] Failed to enable vpn process on router 70e88c46-c6b2-4c8d-afad-76ebd77b55cb
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Traceback (most recent call last):
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 251, in enable
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self.ensure_configs()
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/libreswan_ipsec.py", line 31, in ensure_configs
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self._execute([self.binary, '_stackmanager', 'start'])
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 335, in _execute
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes)
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/ip_lib.py", line 580, in execute
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes, **kwargs)
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py", line 137, in execute
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     raise RuntimeError(m)
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec RuntimeError:
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Command: ['ipsec', '_stackmanager', 'start']
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Exit code: 4
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdin:
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdout:
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stderr: permission denied (must be superuser)
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
2015-07-22 14:27:31.382 9532 INFO neutron.callbacks.manager [req-80912c4c-e33c-4fd2-9ab1-1adc55232a83 ] Calling callback neutron.agent.metadata.driver.after_router_added
2015-07-22 14:27:32.645 9532 INFO neutron.callbacks.manager [req-9d73a56c-e036-4982-bfd6-b85428d1ef33 ] Notify callbacks for router, after_create
2015-07-22 14:27:32.646 9532 INFO neutron.callbacks.manager [req-9d73a56c-e036-4982-bfd6-b85428d1ef33 ] Calling callback neutron_vpnaas.services.vpn.vpn_service.router_added_actions
2015-07-22 14:27:32.726 9532 INFO neutron.callbacks.manager [req-58f2f154-d10b-4740-b0a2-ef7705ddbe41 ] Notify callbacks for router, after_create
2015-07-22 14:27:32.726 9532 INFO neutron.callbacks.manager [req-58f2f154-d10b-4740-b0a2-ef7705ddbe41 ] Calling callback neutron_vpnaas.services.vpn.vpn_service.router_added_actions
2015-07-22 14:27:33.214 9532 ERROR neutron.agent.linux.utils [req-9d73a56c-e036-4982-bfd6-b85428d1ef33 ]
Command: ['ipsec', '_stackmanager', 'start']
Exit code: 4
Stdin:
Stdout:
Stderr: permission denied (must be superuser)

2015-07-22 14:27:33.215 9532 ERROR neutron_vpnaas.services.vpn.device_drivers.ipsec [req-9d73a56c-e036-4982-bfd6-b85428d1ef33 ] Failed to enable vpn process on router 70e88c46-c6b2-4c8d-afad-76ebd77b55cb
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Traceback (most recent call last):
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 251, in enable
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self.ensure_configs()
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/libreswan_ipsec.py", line 31, in ensure_configs
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self._execute([self.binary, '_stackmanager', 'start'])
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 335, in _execute
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes)
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/ip_lib.py", line 580, in execute
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 335, in _execute
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes)
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/ip_lib.py", line 580, in execute
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes, **kwargs)
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py", line 137, in execute
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     raise RuntimeError(m)
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec RuntimeError:
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Command: ['ipsec', '_stackmanager', 'start']
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Exit code: 4
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdin:
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdout:
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stderr: permission denied (must be superuser)
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
2015-07-22 14:27:33.326 9532 ERROR neutron.agent.linux.utils [req-58f2f154-d10b-4740-b0a2-ef7705ddbe41 ]
Command: ['ipsec', '_stackmanager', 'start']
Exit code: 4
Stdin:
Stdout:
Stderr: permission denied (must be superuser)

2015-07-22 14:27:33.326 9532 ERROR neutron_vpnaas.services.vpn.device_drivers.ipsec [req-58f2f154-d10b-4740-b0a2-ef7705ddbe41 ] Failed to enable vpn process on router 21f9a7a4-2a3b-48aa-9e4c-88540255cb63
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Traceback (most recent call last):
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 251, in enable
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self.ensure_configs()
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/libreswan_ipsec.py", line 31, in ensure_configs
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self._execute([self.binary, '_stackmanager', 'start'])
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 335, in _execute
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes)
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/ip_lib.py", line 580, in execute
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes, **kwargs)
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py", line 137, in execute
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     raise RuntimeError(m)
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec RuntimeError:
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Command: ['ipsec', '_stackmanager', 'start']
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Exit code: 4
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdin:
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdout:
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stderr: permission denied (must be superuser)
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
2015-07-22 14:27:35.291 9532 ERROR neutron.agent.linux.utils [req-9d73a56c-e036-4982-bfd6-b85428d1ef33 ]
Command: ['sudo', 'neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qrouter-70e88c46-c6b2-4c8d-afad-76ebd77b55cb', 'ipsec', 'pluto', '--ctlbase', '/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/var/run/pluto', '--ipsecdir', '/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/etc', '--use-netkey', '--uniqueids', '--nat_traversal', '--secretsfile', '/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/etc/ipsec.secrets', '--virtual_private', '%v4:10.10.10.0/24,%v4:20.20.20.0/24']
Exit code: 10
Stdin:
Stdout:
Stderr: adjusting ipsec.d to /var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/etc
warning: option "--nat_traversal" is obsolete; ignored
warning: option "--virtual_private" with '_' in its name is obsolete; use '-'
pluto: FATAL: lock file "/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/var/run/pluto.pid" already exists
2015-07-22 14:27:35.292 9532 ERROR neutron_vpnaas.services.vpn.device_drivers.ipsec [req-9d73a56c-e036-4982-bfd6-b85428d1ef33 ] Failed to enable vpn process on router 70e88c46-c6b2-4c8d-afad-76ebd77b55cb
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Traceback (most recent call last):
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 255, in enable
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self.start()
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 425, in start
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     '--virtual_private', virtual_private
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 335, in _execute
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes)
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/ip_lib.py", line 580, in execute
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes, **kwargs)
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py", line 137, in execute
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     raise RuntimeError(m)
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec RuntimeError:
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Command: ['sudo', 'neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qrouter-70e88c46-c6b2-4c8d-afad-76ebd77b55cb', 'ipsec', 'pluto', '--ctlbase', '/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/var/run/pluto', '--ipsecdir', '/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/etc', '--use-netkey', '--uniqueids', '--nat_traversal', '--secretsfile', '/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/etc/ipsec.secrets', '--virtual_private', '%v4:10.10.10.0/24,%v4:20.20.20.0/24']
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Exit code: 10
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdin:
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdout:
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stderr: adjusting ipsec.d to /var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/etc
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec warning: option "--nat_traversal" is obsolete; ignored
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec warning: option "--virtual_private" with '_' in its name is obsolete; use '-'
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec pluto: FATAL: lock file "/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/var/run/pluto.pid" already exists
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
2015-07-22 14:27:35.542 9532 INFO neutron.callbacks.manager [req-9d73a56c-e036-4982-bfd6-b85428d1ef33 ] Calling callback neutron.agent.metadata.driver.after_router_added
2015-07-22 14:27:37.595 9532 ERROR neutron.agent.linux.utils [req-58f2f154-d10b-4740-b0a2-ef7705ddbe41 ]
Command: ['sudo', 'neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qrouter-21f9a7a4-2a3b-48aa-9e4c-88540255cb63', 'ipsec', 'pluto', '--ctlbase', '/var/lib/neutron/ipsec/21f9a7a4-2a3b-48aa-9e4c-88540255cb63/var/run/pluto', '--ipsecdir', '/var/lib/neutron/ipsec/21f9a7a4-2a3b-48aa-9e4c-88540255cb63/etc', '--use-netkey', '--uniqueids', '--nat_traversal', '--secretsfile', '/var/lib/neutron/ipsec/21f9a7a4-2a3b-48aa-9e4c-88540255cb63/etc/ipsec.secrets', '--virtual_private', '%v4:20.20.20.0/24,%v4:10.10.10.0/24']
Exit code: 10
Stdin:
Stdout:
Stderr: adjusting ipsec.d to /var/lib/neutron/ipsec/21f9a7a4-2a3b-48aa-9e4c-88540255cb63/etc
warning: option "--nat_traversal" is obsolete; ignored
warning: option "--virtual_private" with '_' in its name is obsolete; use '-'
pluto: FATAL: lock file "/var/lib/neutron/ipsec/21f9a7a4-2a3b-48aa-9e4c-88540255cb63/var/run/pluto.pid" already exists

** Affects: neutron
     Importance: Undecided
         Status: New

-- 
You received this bug notification because you are a member of Yahoo!
Engineering Team, which is subscribed to neutron.
https://bugs.launchpad.net/bugs/1477030

Title:
  VPNaas: rdo-kilo: restarting vpn agent with active tunnels, will not
  bring up exisiting tunnels

Status in neutron:
  New

Bug description:
  rdo-kilo vpnaas on centos71

  1. With existing tunnels, if vpn agent is restarted, the tunnels will
  not come up...

  2. 
  [root@ceos71 ~(keystone_admin)]# neutron  vpn-service-list
  +--------------------------------------+------+--------------------------------------+--------+
  | id                                   | name | router_id                            | status |
  +--------------------------------------+------+--------------------------------------+--------+
  | 67189109-76cf-493d-9c20-3bf430068d8d | vpn2 | 21f9a7a4-2a3b-48aa-9e4c-88540255cb63 | ACTIVE |
  | c0e27fe8-552c-440f-8eaa-709c3ee01b18 | vpn1 | 70e88c46-c6b2-4c8d-afad-76ebd77b55cb | ACTIVE |
  +--------------------------------------+------+--------------------------------------+--------+
  [root@ceos71 ~(keystone_admin)]# neutron  ipsec-site-connection-list
  +--------------------------------------+-------+-----------------+-----------------+------------+-----------+----------------+
  | id                                   | name  | peer_address    | peer_cidrs      | route_mode | auth_mode | status         |
  +--------------------------------------+-------+-----------------+-----------------+------------+-----------+----------------+
  | 89931e0f-6e8a-4e8a-8063-5aa974d70288 | 1vpn1 | 192.168.122.203 | "20.20.20.0/24" | static     | psk       | PENDING_CREATE |
  | d16db820-fced-4e00-b750-a25a7d2b7a56 | 1vpn2 | 192.168.122.202 | "10.10.10.0/24" | static     | psk       | PENDING_CREATE |
  +--------------------------------------+-------+-----------------+-----------------+------------+-----------+----------------+

  3. traffic going fine and tunnels are up
  [root@ceos71 ~(keystone_admin)]# /bin/neutron-rootwrap /etc/neutron/rootwrap.conf ip netns exec qrouter-70e88c46-c6b2-4c8d-afad-76ebd77b55cb ipsec whack --ctlbase /var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/var/run/pluto --trafficstatus
  000  
  006 #2: "89931e0f-6e8a-4e8a-8063-5aa974d70288/0x1", type=ESP,  add_time=1437555102, inBytes=0, outBytes=0
  006 #4: "89931e0f-6e8a-4e8a-8063-5aa974d70288/0x1", type=ESP,  add_time=1437555123, inBytes=45140, outBytes=36112
  000  
  [root@ceos71 ~(keystone_admin)]# 
  [root@ceos71 ~(keystone_admin)]# 
  [root@ceos71 ~(keystone_admin)]# /bin/neutron-rootwrap /etc/neutron/rootwrap.conf ip netns exec qrouter-21f9a7a4-2a3b-48aa-9e4c-88540255cb63 ipsec whack --ctlbase /var/lib/neutron/ipsec/21f9a7a4-2a3b-48aa-9e4c-88540255cb63/var/run/pluto --trafficstatus
  000  
  006 #2: "d16db820-fced-4e00-b750-a25a7d2b7a56/0x1", type=ESP,  add_time=1437555123, inBytes=36112, outBytes=45140
  000  
  [root@ceos71 ~(keystone_admin)]# 

  4. [root@ceos71 ~(keystone_admin)]#  service neutron-vpn-agent restart
  Redirecting to /bin/systemctl restart  neutron-vpn-agent.service
  [root@ceos71 ~(keystone_admin)]# 

  5. [root@ceos71 ~(keystone_admin)]# /bin/neutron-rootwrap /etc/neutron/rootwrap.conf ip netns exec qrouter-21f9a7a4-2a3b-48aa-9e4c-88540255cb63 ipsec whack --ctlbase /var/lib/neutron/ipsec/21f9a7a4-2a3b-48aa-9e4c-88540255cb63/var/run/pluto --trafficstatus
  whack: is Pluto running?  connect() for "/var/lib/neutron/ipsec/21f9a7a4-2a3b-48aa-9e4c-88540255cb63/var/run/pluto.ctl" failed (111 Connection refused)
  [root@ceos71 ~(keystone_admin)]# 
  [root@ceos71 ~(keystone_admin)]# 
  [root@ceos71 ~(keystone_admin)]# 
  [root@ceos71 ~(keystone_admin)]# /bin/neutron-rootwrap /etc/neutron/rootwrap.conf ip netns exec qrouter-70e88c46-c6b2-4c8d-afad-76ebd77b55cb ipsec whack --ctlbase /var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/var/run/pluto --trafficstatus
  whack: is Pluto running?  connect() for "/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/var/run/pluto.ctl" failed (111 Connection refused)
  [root@ceos71 ~(keystone_admin)]# 

  ==========
  vpn agnet logs, when vpn agent is restarted

  
  2015-07-22 14:27:27.792 7946 INFO neutron.openstack.common.service [req-6defd1a3-dd67-4831-9062-65b7515f02f6 ] Caught SIGTERM, exiting
  2015-07-22 14:27:27.945 7946 ERROR oslo_messaging._drivers.impl_rabbit [-] Failed to consume message from queue:
  2015-07-22 14:27:28.994 9532 INFO neutron.common.config [-] Logging enabled!
  2015-07-22 14:27:28.994 9532 INFO neutron.common.config [-] /usr/bin/neutron-vpn-agent version 2015.1.0
  2015-07-22 14:27:28.995 9532 WARNING oslo_config.cfg [-] Option "use_namespaces" from group "DEFAULT" is deprecated for removal.  Its value may be silently ignored in the future.
  2015-07-22 14:27:29.014 9532 INFO oslo_messaging._drivers.impl_rabbit [req-d12bbe5c-ea44-4e2f-9627-f3675e6fa6cf ] Connecting to AMQP server on 192.168.122.30:5672
  2015-07-22 14:27:29.030 9532 INFO oslo_messaging._drivers.impl_rabbit [req-d12bbe5c-ea44-4e2f-9627-f3675e6fa6cf ] Connected to AMQP server on 192.168.122.30:5672
  2015-07-22 14:27:29.037 9532 INFO oslo_messaging._drivers.impl_rabbit [req-d12bbe5c-ea44-4e2f-9627-f3675e6fa6cf ] Connecting to AMQP server on 192.168.122.30:5672
  2015-07-22 14:27:29.053 9532 INFO oslo_messaging._drivers.impl_rabbit [req-d12bbe5c-ea44-4e2f-9627-f3675e6fa6cf ] Connected to AMQP server on 192.168.122.30:5672
  2015-07-22 14:27:29.092 9532 WARNING neutron.services.provider_configuration [req-d12bbe5c-ea44-4e2f-9627-f3675e6fa6cf ] The configured driver neutron.services.firewall.drivers.linux.iptables_fwaas.IptablesFwaasDriver has been moved, automatically using neutron_fwaas.services.firewall.drivers.linux.iptables_fwaas.IptablesFwaasDriver instead. Please update your config files, as this automatic fixup will be removed in a future release.
  2015-07-22 14:27:29.101 9532 INFO oslo_messaging._drivers.impl_rabbit [req-58dc3919-9ee5-419b-aa72-99beda2bb3f6 ] Connecting to AMQP server on 192.168.122.30:5672
  2015-07-22 14:27:29.147 9532 INFO eventlet.wsgi.server [-] (9532) wsgi starting up on http:///:v/
  2015-07-22 14:27:29.151 9532 INFO oslo_messaging._drivers.impl_rabbit [req-58dc3919-9ee5-419b-aa72-99beda2bb3f6 ] Connected to AMQP server on 192.168.122.30:5672
  2015-07-22 14:27:29.170 9532 WARNING oslo_config.cfg [req-58dc3919-9ee5-419b-aa72-99beda2bb3f6 ] Option "nova_region_name" from group "DEFAULT" is deprecated. Use option "region_name" from group "nova".
  2015-07-22 14:27:29.172 9532 INFO oslo_messaging._drivers.impl_rabbit [-] Connecting to AMQP server on 192.168.122.30:5672
  2015-07-22 14:27:29.188 9532 INFO oslo_messaging._drivers.impl_rabbit [-] Connected to AMQP server on 192.168.122.30:5672
  2015-07-22 14:27:29.197 9532 INFO neutron.agent.l3.agent [-] L3 agent started
  2015-07-22 14:27:29.628 9532 INFO oslo_messaging._drivers.impl_rabbit [-] Connecting to AMQP server on 192.168.122.30:5672
  2015-07-22 14:27:29.188 9532 INFO oslo_messaging._drivers.impl_rabbit [-] Connected to AMQP server on 192.168.122.30:5672
  2015-07-22 14:27:29.197 9532 INFO neutron.agent.l3.agent [-] L3 agent started
  2015-07-22 14:27:29.628 9532 INFO oslo_messaging._drivers.impl_rabbit [-] Connecting to AMQP server on 192.168.122.30:5672
  2015-07-22 14:27:29.641 9532 INFO oslo_messaging._drivers.impl_rabbit [-] Connecting to AMQP server on 192.168.122.30:5672
  2015-07-22 14:27:29.668 9532 INFO oslo_messaging._drivers.impl_rabbit [-] Connected to AMQP server on 192.168.122.30:5672
  2015-07-22 14:27:29.669 9532 INFO oslo_messaging._drivers.impl_rabbit [-] Connected to AMQP server on 192.168.122.30:5672
  2015-07-22 14:27:29.750 9532 INFO neutron.callbacks.manager [-] Notify callbacks for router, before_create
  2015-07-22 14:27:29.769 9532 INFO neutron.callbacks.manager [-] Notify callbacks for router, before_create
  2015-07-22 14:27:29.786 9532 INFO neutron.callbacks.manager [-] Notify callbacks for router, before_create
  2015-07-22 14:27:31.116 9532 INFO neutron.callbacks.manager [req-80912c4c-e33c-4fd2-9ab1-1adc55232a83 ] Notify callbacks for router, after_create
  2015-07-22 14:27:31.117 9532 INFO neutron.callbacks.manager [req-80912c4c-e33c-4fd2-9ab1-1adc55232a83 ] Calling callback neutron_vpnaas.services.vpn.vpn_service.router_added_actions
  2015-07-22 14:27:31.331 9532 ERROR neutron.agent.linux.utils [req-80912c4c-e33c-4fd2-9ab1-1adc55232a83 ]
  Command: ['ipsec', '_stackmanager', 'start']
  Exit code: 4
  Stdin:
  Stdout:
  Stderr: permission denied (must be superuser)

  2015-07-22 14:27:31.332 9532 ERROR neutron_vpnaas.services.vpn.device_drivers.ipsec [req-80912c4c-e33c-4fd2-9ab1-1adc55232a83 ] Failed to enable vpn process on router 21f9a7a4-2a3b-48aa-9e4c-88540255cb63
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Traceback (most recent call last):
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 251, in enable
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self.ensure_configs()
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/libreswan_ipsec.py", line 31, in ensure_configs
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self._execute([self.binary, '_stackmanager', 'start'])
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 335, in _execute
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes)
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/ip_lib.py", line 580, in execute
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes, **kwargs)
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py", line 137, in execute
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     raise RuntimeError(m)
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec RuntimeError:
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Command: ['ipsec', '_stackmanager', 'start']
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Exit code: 4
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdin:
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdout:
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stderr: permission denied (must be superuser)
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
  2015-07-22 14:27:31.332 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
  2015-07-22 14:27:31.349 9532 ERROR neutron.agent.linux.utils [req-80912c4c-e33c-4fd2-9ab1-1adc55232a83 ]
  Command: ['ipsec', '_stackmanager', 'start']
  Exit code: 4
  Stdin:
  Stdout:
  Stderr: permission denied (must be superuser)

  2015-07-22 14:27:31.350 9532 ERROR neutron_vpnaas.services.vpn.device_drivers.ipsec [req-80912c4c-e33c-4fd2-9ab1-1adc55232a83 ] Failed to enable vpn process on router 70e88c46-c6b2-4c8d-afad-76ebd77b55cb
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Traceback (most recent call last):
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 251, in enable
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self.ensure_configs()
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/libreswan_ipsec.py", line 31, in ensure_configs
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self._execute([self.binary, '_stackmanager', 'start'])
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 335, in _execute
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes)
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/ip_lib.py", line 580, in execute
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes, **kwargs)
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py", line 137, in execute
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     raise RuntimeError(m)
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec RuntimeError:
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Command: ['ipsec', '_stackmanager', 'start']
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Exit code: 4
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdin:
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdout:
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stderr: permission denied (must be superuser)
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
  2015-07-22 14:27:31.350 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
  2015-07-22 14:27:31.382 9532 INFO neutron.callbacks.manager [req-80912c4c-e33c-4fd2-9ab1-1adc55232a83 ] Calling callback neutron.agent.metadata.driver.after_router_added
  2015-07-22 14:27:32.645 9532 INFO neutron.callbacks.manager [req-9d73a56c-e036-4982-bfd6-b85428d1ef33 ] Notify callbacks for router, after_create
  2015-07-22 14:27:32.646 9532 INFO neutron.callbacks.manager [req-9d73a56c-e036-4982-bfd6-b85428d1ef33 ] Calling callback neutron_vpnaas.services.vpn.vpn_service.router_added_actions
  2015-07-22 14:27:32.726 9532 INFO neutron.callbacks.manager [req-58f2f154-d10b-4740-b0a2-ef7705ddbe41 ] Notify callbacks for router, after_create
  2015-07-22 14:27:32.726 9532 INFO neutron.callbacks.manager [req-58f2f154-d10b-4740-b0a2-ef7705ddbe41 ] Calling callback neutron_vpnaas.services.vpn.vpn_service.router_added_actions
  2015-07-22 14:27:33.214 9532 ERROR neutron.agent.linux.utils [req-9d73a56c-e036-4982-bfd6-b85428d1ef33 ]
  Command: ['ipsec', '_stackmanager', 'start']
  Exit code: 4
  Stdin:
  Stdout:
  Stderr: permission denied (must be superuser)

  2015-07-22 14:27:33.215 9532 ERROR neutron_vpnaas.services.vpn.device_drivers.ipsec [req-9d73a56c-e036-4982-bfd6-b85428d1ef33 ] Failed to enable vpn process on router 70e88c46-c6b2-4c8d-afad-76ebd77b55cb
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Traceback (most recent call last):
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 251, in enable
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self.ensure_configs()
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/libreswan_ipsec.py", line 31, in ensure_configs
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self._execute([self.binary, '_stackmanager', 'start'])
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 335, in _execute
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes)
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/ip_lib.py", line 580, in execute
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 335, in _execute
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes)
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/ip_lib.py", line 580, in execute
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes, **kwargs)
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py", line 137, in execute
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     raise RuntimeError(m)
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec RuntimeError:
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Command: ['ipsec', '_stackmanager', 'start']
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Exit code: 4
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdin:
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdout:
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stderr: permission denied (must be superuser)
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
  2015-07-22 14:27:33.215 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
  2015-07-22 14:27:33.326 9532 ERROR neutron.agent.linux.utils [req-58f2f154-d10b-4740-b0a2-ef7705ddbe41 ]
  Command: ['ipsec', '_stackmanager', 'start']
  Exit code: 4
  Stdin:
  Stdout:
  Stderr: permission denied (must be superuser)

  2015-07-22 14:27:33.326 9532 ERROR neutron_vpnaas.services.vpn.device_drivers.ipsec [req-58f2f154-d10b-4740-b0a2-ef7705ddbe41 ] Failed to enable vpn process on router 21f9a7a4-2a3b-48aa-9e4c-88540255cb63
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Traceback (most recent call last):
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 251, in enable
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self.ensure_configs()
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/libreswan_ipsec.py", line 31, in ensure_configs
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self._execute([self.binary, '_stackmanager', 'start'])
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 335, in _execute
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes)
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/ip_lib.py", line 580, in execute
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes, **kwargs)
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py", line 137, in execute
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     raise RuntimeError(m)
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec RuntimeError:
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Command: ['ipsec', '_stackmanager', 'start']
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Exit code: 4
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdin:
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdout:
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stderr: permission denied (must be superuser)
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
  2015-07-22 14:27:33.326 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
  2015-07-22 14:27:35.291 9532 ERROR neutron.agent.linux.utils [req-9d73a56c-e036-4982-bfd6-b85428d1ef33 ]
  Command: ['sudo', 'neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qrouter-70e88c46-c6b2-4c8d-afad-76ebd77b55cb', 'ipsec', 'pluto', '--ctlbase', '/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/var/run/pluto', '--ipsecdir', '/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/etc', '--use-netkey', '--uniqueids', '--nat_traversal', '--secretsfile', '/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/etc/ipsec.secrets', '--virtual_private', '%v4:10.10.10.0/24,%v4:20.20.20.0/24']
  Exit code: 10
  Stdin:
  Stdout:
  Stderr: adjusting ipsec.d to /var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/etc
  warning: option "--nat_traversal" is obsolete; ignored
  warning: option "--virtual_private" with '_' in its name is obsolete; use '-'
  pluto: FATAL: lock file "/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/var/run/pluto.pid" already exists
  2015-07-22 14:27:35.292 9532 ERROR neutron_vpnaas.services.vpn.device_drivers.ipsec [req-9d73a56c-e036-4982-bfd6-b85428d1ef33 ] Failed to enable vpn process on router 70e88c46-c6b2-4c8d-afad-76ebd77b55cb
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Traceback (most recent call last):
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 255, in enable
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     self.start()
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 425, in start
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     '--virtual_private', virtual_private
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron_vpnaas/services/vpn/device_drivers/ipsec.py", line 335, in _execute
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes)
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/ip_lib.py", line 580, in execute
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     extra_ok_codes=extra_ok_codes, **kwargs)
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec   File "/usr/lib/python2.7/site-packages/neutron/agent/linux/utils.py", line 137, in execute
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec     raise RuntimeError(m)
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec RuntimeError:
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Command: ['sudo', 'neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qrouter-70e88c46-c6b2-4c8d-afad-76ebd77b55cb', 'ipsec', 'pluto', '--ctlbase', '/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/var/run/pluto', '--ipsecdir', '/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/etc', '--use-netkey', '--uniqueids', '--nat_traversal', '--secretsfile', '/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/etc/ipsec.secrets', '--virtual_private', '%v4:10.10.10.0/24,%v4:20.20.20.0/24']
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Exit code: 10
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdin:
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stdout:
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec Stderr: adjusting ipsec.d to /var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/etc
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec warning: option "--nat_traversal" is obsolete; ignored
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec warning: option "--virtual_private" with '_' in its name is obsolete; use '-'
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec pluto: FATAL: lock file "/var/lib/neutron/ipsec/70e88c46-c6b2-4c8d-afad-76ebd77b55cb/var/run/pluto.pid" already exists
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
  2015-07-22 14:27:35.292 9532 TRACE neutron_vpnaas.services.vpn.device_drivers.ipsec
  2015-07-22 14:27:35.542 9532 INFO neutron.callbacks.manager [req-9d73a56c-e036-4982-bfd6-b85428d1ef33 ] Calling callback neutron.agent.metadata.driver.after_router_added
  2015-07-22 14:27:37.595 9532 ERROR neutron.agent.linux.utils [req-58f2f154-d10b-4740-b0a2-ef7705ddbe41 ]
  Command: ['sudo', 'neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'ip', 'netns', 'exec', 'qrouter-21f9a7a4-2a3b-48aa-9e4c-88540255cb63', 'ipsec', 'pluto', '--ctlbase', '/var/lib/neutron/ipsec/21f9a7a4-2a3b-48aa-9e4c-88540255cb63/var/run/pluto', '--ipsecdir', '/var/lib/neutron/ipsec/21f9a7a4-2a3b-48aa-9e4c-88540255cb63/etc', '--use-netkey', '--uniqueids', '--nat_traversal', '--secretsfile', '/var/lib/neutron/ipsec/21f9a7a4-2a3b-48aa-9e4c-88540255cb63/etc/ipsec.secrets', '--virtual_private', '%v4:20.20.20.0/24,%v4:10.10.10.0/24']
  Exit code: 10
  Stdin:
  Stdout:
  Stderr: adjusting ipsec.d to /var/lib/neutron/ipsec/21f9a7a4-2a3b-48aa-9e4c-88540255cb63/etc
  warning: option "--nat_traversal" is obsolete; ignored
  warning: option "--virtual_private" with '_' in its name is obsolete; use '-'
  pluto: FATAL: lock file "/var/lib/neutron/ipsec/21f9a7a4-2a3b-48aa-9e4c-88540255cb63/var/run/pluto.pid" already exists

To manage notifications about this bug go to:
https://bugs.launchpad.net/neutron/+bug/1477030/+subscriptions

Follow ups

  Thread Previous • Date Previous • • Thread Next