Details
-
Bug
-
Status: Closed
-
Critical
-
Resolution: Fixed
-
4.8.0, 4.9.0
-
None
-
Security Level: Public (Anyone can view this level - this is the default.)
-
None
-
Two CentOS7 MGMT Servers, Two XenServerClusters, Advanced Networking, VLAN isolated
Description
When we try to add an VPN User on a VPC following error occurs:
Management Server:
—
Apr 20 09:24:43 WARN [resource.virtualnetwork.VirtualRoutingResource] (DirectAgent-68:ctx-de5cbf45) (logid:180e35ed) Expected 1 answers while executing VpnUsersCfgCommand but received 2
Apr 20 09:24:43 admin02 server: WARN [c.c.a.r.v.VirtualRoutingResource] (DirectAgent-68:ctx-de5cbf45) (logid:180e35ed) Expected 1 answers while executing VpnUsersCfgCommand but received 2
Apr 20 09:24:47 WARN [resource.virtualnetwork.VirtualRoutingResource] (DirectAgent-268:ctx-873174f6) (logid:180e35ed) Expected 1 answers while executing VpnUsersCfgCommand but received 2
Apr 20 09:24:47 admin02 server: WARN [c.c.a.r.v.VirtualRoutingResource] (DirectAgent-268:ctx-873174f6) (logid:180e35ed) Expected 1 answers while executing VpnUsersCfgCommand but received 2
Apr 20 09:24:47 WARN [network.vpn.RemoteAccessVpnManagerImpl] (API-Job-Executor-58:ctx-7f86f610 job-1169 ctx-1073feac) (logid:180e35ed) Unable to apply vpn users
Apr 20 09:24:47 localhost java.lang.IndexOutOfBoundsException: Index: 1, Size: 1
Apr 20 09:24:47 localhost at java.util.ArrayList.rangeCheck(ArrayList.java:653)
Apr 20 09:24:47 localhost at java.util.ArrayList.get(ArrayList.java:429)
Apr 20 09:24:47 localhost at com.cloud.network.vpn.RemoteAccessVpnManagerImpl.applyVpnUsers(RemoteAccessVpnManagerImpl.java:532)
Apr 20 09:24:47 localhost at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
Apr 20 09:24:47 localhost at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
Apr 20 09:24:47 localhost at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Apr 20 09:24:47 localhost at java.lang.reflect.Method.invoke(Method.java:498)
Apr 20 09:24:47 localhost at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
Apr 20 09:24:47 localhost at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
Apr 20 09:24:47 localhost at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
Apr 20 09:24:47 localhost at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
Apr 20 09:24:47 localhost at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
Apr 20 09:24:47 localhost at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
Apr 20 09:24:47 localhost at com.sun.proxy.$Proxy234.applyVpnUsers(Unknown Source)
Apr 20 09:24:47 localhost at org.apache.cloudstack.api.command.user.vpn.AddVpnUserCmd.execute(AddVpnUserCmd.java:122)
Apr 20 09:24:47 localhost at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:150)
Apr 20 09:24:47 localhost at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
Apr 20 09:24:47 localhost at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:554)
Apr 20 09:24:47 localhost at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
Apr 20 09:24:47 localhost at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
Apr 20 09:24:47 localhost at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
Apr 20 09:24:47 localhost at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
Apr 20 09:24:47 localhost at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
Apr 20 09:24:47 localhost at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:502)
Apr 20 09:24:47 localhost at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
Apr 20 09:24:47 localhost at java.util.concurrent.FutureTask.run(FutureTask.java:266)
Apr 20 09:24:47 localhost at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
Apr 20 09:24:47 localhost at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
Apr 20 09:24:47 localhost at java.lang.Thread.run(Thread.java:745)
Apr 20 09:24:47 admin02 server: WARN [c.c.n.v.RemoteAccessVpnManagerImpl] (API-Job-Executor-58:ctx-7f86f610 job-1169 ctx-1073feac) (logid:180e35ed) Unable to apply vpn users
Apr 20 09:24:47 admin02 server: java.lang.IndexOutOfBoundsException: Index: 1, Size: 1
Apr 20 09:24:47 admin02 server: at java.util.ArrayList.rangeCheck(ArrayList.java:653)
Apr 20 09:24:47 admin02 server: at java.util.ArrayList.get(ArrayList.java:429)
Apr 20 09:24:47 admin02 server: at com.cloud.network.vpn.RemoteAccessVpnManagerImpl.applyVpnUsers(RemoteAccessVpnManagerImpl.java:532)
Apr 20 09:24:47 admin02 server: at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
Apr 20 09:24:47 admin02 server: at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
Apr 20 09:24:47 admin02 server: at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
Apr 20 09:24:47 admin02 server: at java.lang.reflect.Method.invoke(Method.java:498)
Apr 20 09:24:47 admin02 server: at org.springframework.aop.support.AopUtils.invokeJoinpointUsingReflection(AopUtils.java:317)
Apr 20 09:24:47 admin02 server: at org.springframework.aop.framework.ReflectiveMethodInvocation.invokeJoinpoint(ReflectiveMethodInvocation.java:183)
Apr 20 09:24:47 admin02 server: at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:150)
Apr 20 09:24:47 admin02 server: at org.springframework.aop.interceptor.ExposeInvocationInterceptor.invoke(ExposeInvocationInterceptor.java:91)
Apr 20 09:24:47 admin02 server: at org.springframework.aop.framework.ReflectiveMethodInvocation.proceed(ReflectiveMethodInvocation.java:172)
Apr 20 09:24:47 admin02 server: at org.springframework.aop.framework.JdkDynamicAopProxy.invoke(JdkDynamicAopProxy.java:204)
Apr 20 09:24:47 admin02 server: at com.sun.proxy.$Proxy234.applyVpnUsers(Unknown Source)
Apr 20 09:24:47 admin02 server: at org.apache.cloudstack.api.command.user.vpn.AddVpnUserCmd.execute(AddVpnUserCmd.java:122)
Apr 20 09:24:47 admin02 server: at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:150)
Apr 20 09:24:47 admin02 server: at com.cloud.api.ApiAsyncJobDispatcher.runJob(ApiAsyncJobDispatcher.java:108)
Apr 20 09:24:47 admin02 server: at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.runInContext(AsyncJobManagerImpl.java:554)
Apr 20 09:24:47 admin02 server: at org.apache.cloudstack.managed.context.ManagedContextRunnable$1.run(ManagedContextRunnable.java:49)
Apr 20 09:24:47 admin02 server: at org.apache.cloudstack.managed.context.impl.DefaultManagedContext$1.call(DefaultManagedContext.java:56)
Apr 20 09:24:47 admin02 server: at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.callWithContext(DefaultManagedContext.java:103)
Apr 20 09:24:47 admin02 server: at org.apache.cloudstack.managed.context.impl.DefaultManagedContext.runWithContext(DefaultManagedContext.java:53)
Apr 20 09:24:47 admin02 server: at org.apache.cloudstack.managed.context.ManagedContextRunnable.run(ManagedContextRunnable.java:46)
Apr 20 09:24:47 admin02 server: at org.apache.cloudstack.framework.jobs.impl.AsyncJobManagerImpl$5.run(AsyncJobManagerImpl.java:502)
Apr 20 09:24:47 admin02 server: at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
Apr 20 09:24:47 admin02 server: at java.util.concurrent.FutureTask.run(FutureTask.java:266)
Apr 20 09:24:47 admin02 server: at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1142)
Apr 20 09:24:47 admin02 server: at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:617)
Apr 20 09:24:47 admin02 server: at java.lang.Thread.run(Thread.java:745)
Apr 20 09:24:48 WARN [resource.virtualnetwork.VirtualRoutingResource] (DirectAgent-273:ctx-e224fd43) (logid:180e35ed) Expected 1 answers while executing VpnUsersCfgCommand but received 2
Apr 20 09:24:48 admin02 server: WARN [c.c.a.r.v.VirtualRoutingResource] (DirectAgent-273:ctx-e224fd43) (logid:180e35ed) Expected 1 answers while executing VpnUsersCfgCommand but received 2
Apr 20 09:24:49 admin02 server: INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-1a18ac7a) (logid:51e6f749) Begin cleanup expired async-jobs
Apr 20 09:24:49 admin02 server: INFO [o.a.c.f.j.i.AsyncJobManagerImpl] (AsyncJobMgr-Heartbeat-1:ctx-1a18ac7a) (logid:51e6f749) End cleanup expired async-jobs
Apr 20 09:24:51 WARN [resource.virtualnetwork.VirtualRoutingResource] (DirectAgent-137:ctx-f25bab62) (logid:180e35ed) Expected 1 answers while executing VpnUsersCfgCommand but received 2
Apr 20 09:24:51 admin02 server: WARN [c.c.a.r.v.VirtualRoutingResource] (DirectAgent-137:ctx-f25bab62) (logid:180e35ed) Expected 1 answers while executing VpnUsersCfgCommand but received 2
Apr 20 09:24:51 admin02 server: INFO [o.a.c.f.j.i.AsyncJobMonitor] (API-Job-Executor-58:ctx-7f86f610 job-1169) (logid:180e35ed) Remove job-1169 from job monitoring
RouterVM:
—
2016-04-20 07:34:49,139 merge.py load:60 Loading data bag type vpnuserlist
2016-04-20 07:34:49,140 merge.py process:100 Command of type vpnuserlist received
2016-04-20 07:34:49,141 merge.py save:71 Writing data bag type vpnuserlist
2016-04-20 07:34:49,141 merge.py save:72 {u'test':
, u'id': u'vpnuserlist'}
2016-04-20 07:34:49,142 merge.py load:60 Loading data bag type ips
2016-04-20 07:34:49,142 merge.py load:60 Loading data bag type cmdline
2016-04-20 07:34:49,143 configure.py main:925 Configuring ip addresses
2016-04-20 07:34:49,143 CsHelper.py execute:160 Executing: ip addr show dev eth1
2016-04-20 07:34:49,155 CsHelper.py execute:160 Executing: ip addr show dev eth0
2016-04-20 07:34:49,166 CsHelper.py execute:160 Executing: ip addr show dev eth1
2016-04-20 07:34:49,177 CsAddress.py process:110 Address found in DataBag ==>
2016-04-20 07:34:49,178 CsAddress.py process:119 Address 192.168.8.149/28 on device eth1 not configured
2016-04-20 07:34:49,179 CsAddress.py configure:277 Configuring address 192.168.8.149/28 on device eth1
2016-04-20 07:34:49,189 CsRoute.py add_table:38 Adding route table: 1 Table_eth1 to /etc/iproute2/rt_tables if not present
2016-04-20 07:34:49,190 CsHelper.py execute:160 Executing: ip rule show
2016-04-20 07:34:49,201 CsHelper.py execute:160 Executing: ip link show eth1 | grep 'state DOWN'
2016-04-20 07:34:49,216 CsHelper.py execute:160 Executing: arping -c 1 -I eth1 -A -U -s 192.168.8.149 192.168.8.145
2016-04-20 07:34:49,227 CsAddress.py inKernel:689 rpsfr is present in the kernel
2016-04-20 07:34:49,227 CsAddress.py cpus:699 Single CPU machine
2016-04-20 07:34:49,227 CsRoute.py add_table:38 Adding route table: 1 Table_eth1 to /etc/iproute2/rt_tables if not present
2016-04-20 07:34:49,228 CsRoute.py add_route:50 Adding route: dev eth1 table: Table_eth1 network: 192.168.8.144/28 if not present
2016-04-20 07:34:49,228 CsHelper.py execute:160 Executing: ip route show dev eth1 table Table_eth1 192.168.8.144/28
2016-04-20 07:34:49,239 CsRoute.py set_route:60 Add dev eth1 table Table_eth1 192.168.8.144/28
2016-04-20 07:34:49,239 CsHelper.py execute:160 Executing: ip route add dev eth1 table Table_eth1 192.168.8.144/28
2016-04-20 07:34:49,251 CsRoute.py defaultroute_exists:89 Checking if default ipv4 route is present
2016-04-20 07:34:49,251 CsHelper.py execute:160 Executing: ip -4 route list 0/0
2016-04-20 07:34:49,262 CsRoute.py defaultroute_exists:96 No default route found!
2016-04-20 07:34:49,262 CsRoute.py add_defaultroute:81 Adding default route
2016-04-20 07:34:49,262 CsHelper.py execute:160 Executing: ip route show default via 192.168.8.145
2016-04-20 07:34:49,273 CsRoute.py set_route:60 Add default via 192.168.8.145
2016-04-20 07:34:49,273 CsHelper.py execute:160 Executing: ip route add default via 192.168.8.145
2016-04-20 07:34:49,284 CsHelper.py execute:160 Executing: ip addr show dev eth0
2016-04-20 07:34:49,296 CsAddress.py process:110 Address found in DataBag ==>
2016-04-20 07:34:49,296 CsAddress.py process:119 Address 169.254.1.192/16 on device eth0 not configured
2016-04-20 07:34:49,297 CsAddress.py configure:277 Configuring address 169.254.1.192/16 on device eth0
2016-04-20 07:34:49,308 merge.py load:57 Creating data bag type networkacl
2016-04-20 07:34:49,308 merge.py load:57 Creating data bag type firewallrules
2016-04-20 07:34:49,309 merge.py load:57 Creating data bag type forwardingrules
2016-04-20 07:34:49,309 merge.py load:57 Creating data bag type site2sitevpn
2016-04-20 07:34:49,310 merge.py load:60 Loading data bag type remoteaccessvpn
2016-04-20 07:34:49,311 configure.py process:624 {u'192.168.8.149':
, u'id': u'remoteaccessvpn'}
2016-04-20 07:34:49,311 configure.py process:632 Enabling remote access vpn on 192.168.8.149
2016-04-20 07:34:49,311 CsHelper.py execute2:181 Executing: service ipsec status
2016-04-20 07:34:49,388 CsHelper.py execute2:181 Executing: service ipsec start
2016-04-20 07:34:49,779 CsFile.py load:39 Reading file /etc/ipsec.d/l2tp.conf
2016-04-20 07:34:49,780 CsFile.py search:123 Searching for left= and replacing with left=192.168.8.149
2016-04-20 07:34:49,780 CsFile.py commit:60 Nothing to commit. The /etc/ipsec.d/l2tp.conf file did not change
2016-04-20 07:34:49,780 CsFile.py load:39 Reading file /etc/ipsec.d/ipsec.any.secrets
2016-04-20 07:34:49,781 CsFile.py search:123 Searching for : PSK ""= and replacing with : PSK "****"
2016-04-20 07:34:49,781 CsFile.py commit:60 Nothing to commit. The /etc/ipsec.d/ipsec.any.secrets file did not change
2016-04-20 07:34:49,781 CsFile.py load:39 Reading file /etc/xl2tpd/xl2tpd.conf
2016-04-20 07:34:49,781 CsFile.py search:123 Searching for ip range = and replacing with ip range = 10.1.2.2-10.1.2.8
2016-04-20 07:34:49,781 CsFile.py search:123 Searching for local ip = and replacing with local ip = 10.1.2.1
2016-04-20 07:34:49,782 CsFile.py commit:60 Nothing to commit. The /etc/xl2tpd/xl2tpd.conf file did not change
2016-04-20 07:34:49,782 CsFile.py load:39 Reading file /etc/ppp/options.xl2tpd
2016-04-20 07:34:49,782 CsFile.py search:123 Searching for ms-dns and replacing with ms-dns 10.1.2.1
2016-04-20 07:34:49,782 CsFile.py commit:60 Nothing to commit. The /etc/ppp/options.xl2tpd file did not change
2016-04-20 07:34:49,783 configure.py process:635 Remote accessvpn data bag {u'192.168.8.149':
, u'id': u'remoteaccessvpn'}
2016-04-20 07:34:49,784 CsHelper.py execute:160 Executing: ipsec auto --rereadall
2016-04-20 07:34:49,851 CsHelper.py execute:160 Executing: service xl2tpd stop
2016-04-20 07:34:49,879 CsHelper.py execute:160 Executing: service xl2tpd start
2016-04-20 07:34:49,896 CsHelper.py execute:160 Executing: ipsec auto --rereadsecrets
2016-04-20 07:34:49,916 CsHelper.py execute:160 Executing: ipsec auto --replace L2TP-PSK
2016-04-20 07:34:49,936 merge.py load:57 Creating data bag type loadbalancer
2016-04-20 07:34:49,937 configure.py main:984 Configuring vpn users list
2016-04-20 07:34:49,937 merge.py load:60 Loading data bag type vpnuserlist
2016-04-20 07:34:49,937 configure.py add_l2tp_ipsec_user:575 Adding vpn user test * test *
2016-04-20 07:34:49,937 CsFile.py load:39 Reading file /etc/ppp/chap-secrets
2016-04-20 07:34:49,937 CsFile.py searchString:139 Searching for test * test * string
2016-04-20 07:34:49,938 configure.py add_l2tp_ipsec_user:580 User is not there already, so adding user
2016-04-20 07:34:49,938 configure.py del_l2tp_ipsec_user:591 Deleting the user test
2016-04-20 07:34:49,938 CsFile.py load:39 Reading file /etc/ppp/chap-secrets
2016-04-20 07:34:49,938 CsFile.py deleteLine:154 Searching for test * test * to remove the line
2016-04-20 07:34:49,938 CsFile.py commit:60 Nothing to commit. The /etc/ppp/chap-secrets file did not change
2016-04-20 07:34:49,939 CsFile.py commit:66 Wrote edited file /etc/ppp/chap-secrets
2016-04-20 07:34:49,939 CsFile.py commit:68 Updated file in-cache configuration
2016-04-20 07:34:49,939 CsRedundant.py set:68 Router redundancy status is True
2016-04-20 07:34:49,939 CsRedundant.py set_backup:257 Setting router to backup
2016-04-20 07:34:49,939 CsRedundant.py set_backup:264 Bringing public interface eth1 down
2016-04-20 07:34:49,939 CsHelper.py execute:160 Executing: ip link set eth1 down
2016-04-20 07:34:49,946 CsHelper.py execute:160 Executing: /usr/sbin/conntrackd -C /etc/conntrackd/conntrackd.conf -d
2016-04-20 07:34:49,953 CsHelper.py execute:160 Executing: service ipsec stop
2016-04-20 07:34:51,449 CsHelper.py service:189 Service ipsec stop
2016-04-20 07:34:51,449 CsHelper.py execute:160 Executing: service xl2tpd stop
2016-04-20 07:34:51,472 CsHelper.py service:189 Service xl2tpd stop
2016-04-20 07:34:51,473 CsHelper.py execute:160 Executing: service dnsmasq stop
2016-04-20 07:34:51,506 CsHelper.py service:189 Service dnsmasq stop
2016-04-20 07:34:51,507 merge.py save:71 Writing data bag type cmdline
2016-04-20 07:34:51,507 merge.py save:72 {u'config':
, u'id': u'cmdline'}
2016-04-20 07:34:51,508 CsRedundant.py set_backup:282 Router switched to backup mode
2016-04-20 07:34:51,508 CsHelper.py execute:160 Executing: service conntrackd stop
2016-04-20 07:34:51,540 CsHelper.py service:189 Service conntrackd stop
2016-04-20 07:34:51,541 CsHelper.py execute:160 Executing: service keepalived stop
2016-04-20 07:34:51,563 CsHelper.py service:189 Service keepalived stop
2016-04-20 07:34:51,564 CsHelper.py execute:160 Executing: mount
Attachments
Issue Links
- links to