Details

    • Type: Bug Bug
    • Status: Closed
    • Priority: Major Major
    • Resolution: Fixed
    • Affects Version/s: 4.0.0, 4.0.1
    • Fix Version/s: 4.0.1, 4.1.0
    • Component/s: Network Controller
    • Security Level: Public (Anyone can view this level - this is the default.)
    • Labels:
      None
    • Environment:
      CentOS 6.3 x86_64
      CS - 4.0.1-0.11

      Description

      Dear colleagues, the problem is clearly a bug:

      I created a VPC
      Further, in my VPN Customer Gateway to the settings
      Gateway 217.70.20.213
      CIDR list 192.168.10.0/24
      IPsec Preshared-Key blablablablablabla
      IKE Encryption 3des
      IKE Hash md5
      IKE DH None
      ESP Encryption 3des
      ESP Hash md5
      Perfect Forward Secrecy None
      IKE lifetime (second) 86 400
      ESP Lifetime (second) 28 800
      Dead Peer Detection Yes

      In the setting of VPC I create VPN Gateway
      When creating a VPN Connection get the error:
      Resource [Site2SiteVpnConnection:15] is unreachable: Failed to apply site-to-site VPN

      catalina.out:

      WARN [cloud.api.ApiDispatcher] (Job-Executor-11:job-463) class com.cloud.api.ServerApiException : Resource [Site2SiteVpnConnection:15] is unreachable: Failed to apply site-to-site VPN
      WARN [cloud.async.AsyncJobManagerImpl] (Job-Executor-11:job-463) Unable to unregister active job 463 from JMX monitoring
      WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1 Unable to update router r-288-VM's VPN connection status
      WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1 Unable to update router r-288-VM's VPN connection status
      WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1 Unable to update router r-288-VM's VPN connection status
      WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1 Unable to update router r-288-VM's VPN connection status
      WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1 Unable to update router r-288-VM's VPN connection status

      management-server.log:

      2013-01-09 21:27:54,587 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-4:null) Ping from 5
      2013-01-09 21:27:54,623 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-2:null) Ping from 3
      2013-01-09 21:28:17,546 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
      2013-01-09 21:28:17,656 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
      2013-01-09 21:28:18,306 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 3 routers.
      2013-01-09 21:28:18,316 DEBUG [agent.transport.Request] (RouterStatusMonitor-1:null) Seq 5-223284290: Sending { Cmd , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 100111, [{"CheckS2SVpnConnectionsCommand":{"vpnIps":[],"accessDetails":

      {"router.ip":"169.254.1.232","router.name":"r-288-VM"}

      ,"wait":30}}] }
      2013-01-09 21:28:18,458 DEBUG [agent.transport.Request] (AgentManager-Handler-3:null) Seq 5-223284290: Processing: { Ans: , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 110, [{"CheckS2SVpnConnectionsAnswer":{"ipToConnected":{},"ipToDetail":{},"details":"CheckS2SVpnConneciontsCommand failed","result":false,"wait":0}}] }
      2013-01-09 21:28:18,458 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-3:null) Seq 5-223284290: No more commands found
      2013-01-09 21:28:18,458 DEBUG [agent.transport.Request] (RouterStatusMonitor-1:null) Seq 5-223284290: Received: { Ans: , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 110,

      { CheckS2SVpnConnectionsAnswer } }
      2013-01-09 21:28:18,458 DEBUG [agent.manager.AgentManagerImpl] (RouterStatusMonitor-1:null) Details from executing class com.cloud.agent.api.CheckS2SVpnConnectionsCommand: CheckS2SVpnConneciontsCommand failed
      2013-01-09 21:28:18,458 WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Unable to update router r-288-VM's VPN connection status
      2013-01-09 21:28:43,063 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) StorageCollector is running...
      2013-01-09 21:28:43,117 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 17-292881626: Received: { Ans: , MgmtId: 52239887788, via: 17, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
      2013-01-09 21:28:45,185 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 3-1166872144: Received: { Ans: , MgmtId: 52239887788, via: 3, Ver: v1, Flags: 10, { GetStorageStatsAnswer } }
      2013-01-09 21:28:47,545 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
      2013-01-09 21:28:47,655 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
      2013-01-09 21:28:48,305 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 3 routers.
      2013-01-09 21:28:48,328 DEBUG [agent.transport.Request] (RouterStatusMonitor-1:null) Seq 5-223284291: Sending { Cmd , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 100111, [{"CheckS2SVpnConnectionsCommand":{"vpnIps":[],"accessDetails":{"router.ip":"169.254.1.232","router.name":"r-288-VM"},"wait":30}}] }
      2013-01-09 21:28:48,430 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 5-223284291: Processing: { Ans: , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 110, [{"CheckS2SVpnConnectionsAnswer":{"ipToConnected":{},"ipToDetail":{},"details":"CheckS2SVpnConneciontsCommand failed","result":false,"wait":0}}] }
      2013-01-09 21:28:48,430 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-9:null) Seq 5-223284291: No more commands found
      2013-01-09 21:28:48,430 DEBUG [agent.transport.Request] (RouterStatusMonitor-1:null) Seq 5-223284291: Received: { Ans: , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 110, { CheckS2SVpnConnectionsAnswer }

      }
      2013-01-09 21:28:48,430 DEBUG [agent.manager.AgentManagerImpl] (RouterStatusMonitor-1:null) Details from executing class com.cloud.agent.api.CheckS2SVpnConnectionsCommand: CheckS2SVpnConneciontsCommand failed
      2013-01-09 21:28:48,430 WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Unable to update router r-288-VM's VPN connection status
      2013-01-09 21:28:49,298 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-7:null) Ping from 11
      2013-01-09 21:28:49,299 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-6:null) Ping from 17
      2013-01-09 21:28:51,594 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) HostStatsCollector is running...

      1. public.png
        67 kB
        Richard Shevel
      2. after_restart_VPC.zip
        82 kB
        Richard Shevel
      3. r-292-vm_log.tar.gz
        90 kB
        Richard Shevel
      4. messages
        33 kB
        Richard Shevel
      5. management-server_afer_upgrade2.zip
        602 kB
        Richard Shevel
      6. management-server_after_upgrade.zip
        159 kB
        Richard Shevel
      7. management-server.zip
        426 kB
        Richard Shevel
      8. catalina.zip
        101 kB
        Richard Shevel
      9. auth.log
        87 kB
        Richard Shevel

        Activity

        Hide
        Sheng Yang added a comment -

        Please attached the full log.

        And you probably need to dig into /var/log/auth.log in VR to see the reason of fail to apply the VPN, most of time it's due to some configuration error on customer gateway part.

        WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1 Unable to update router r-288-VM's VPN connection status

        is not a big issue, it's just a mechanism to check if connection status changed. This one should be easy once we know the reason.

        Show
        Sheng Yang added a comment - Please attached the full log. And you probably need to dig into /var/log/auth.log in VR to see the reason of fail to apply the VPN, most of time it's due to some configuration error on customer gateway part. WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1 Unable to update router r-288-VM's VPN connection status is not a big issue, it's just a mechanism to check if connection status changed. This one should be easy once we know the reason.
        Hide
        Richard Shevel added a comment -

        on VR (r-288-VM)

        /var/log/messages:
        Jan 9 17:06:50 r-288-VM cloud: vpc_guestnw.sh: Create network on interface eth2, gateway 10.3.3.1, network 10.3.3.1/24
        Jan 9 17:06:52 r-288-VM cloud: Setting up dnsmasq for network 10.3.3.1/24
        Jan 9 17:06:55 r-288-VM cloud: Setting up apache web server for eth2
        Jan 9 17:06:55 r-288-VM cloud: Setting up password service for network 10.3.3.1/24, eth eth2
        Jan 9 17:06:55 r-288-VM cloud: edithosts: update 02:00:01:28:00:01 10.3.3.53 voronin to hosts
        Jan 9 17:06:55 r-288-VM cloud: /root/edithosts.sh: setting default router for 10.3.3.53 to 10.3.3.1

        cloud.log
        Wed Jan 9 17:02:00 UTC 2013 Executing cloud-early-config
        Wed Jan 9 17:02:00 UTC 2013 Detected that we are running inside kvm guest
        Wed Jan 9 17:02:00 UTC 2013 Patching scripts oldmd5=e1defa60190950fbd3d5e9c15c5b7c28 newmd5=89f718b371578db5f8caa40a1da141f1
        Wed Jan 9 17:02:01 UTC 2013 Patching cloud service
        Wed Jan 9 17:02:02 UTC 2013 Rebooting system since we patched init scripts
        Wed Jan 9 17:02:17 UTC 2013 Executing cloud-early-config
        Wed Jan 9 17:02:17 UTC 2013 Detected that we are running inside kvm guest
        Wed Jan 9 17:02:18 UTC 2013 Patching cloud service
        Wed Jan 9 17:02:18 UTC 2013 Setting up VPC virtual router system vm
        Wed Jan 9 17:02:19 UTC 2013 Setting up apache web server for VPC
        Wed Jan 9 17:02:19 UTC 2013 Enable service dnsmasq = 1
        Wed Jan 9 17:02:19 UTC 2013 Enable service haproxy = 1
        Wed Jan 9 17:02:19 UTC 2013 Enable service cloud = 0
        Wed Jan 9 17:02:19 UTC 2013 cloud: Tuning rp_filter on public interfaces
        Wed Jan 9 17:02:19 UTC 2013 rpfilter public interfaces :
        Wed Jan 9 17:02:19 UTC 2013 cloud: disable rp_filter on public interfaces
        Wed Jan 9 17:02:19 UTC 2013 cloud: Enabling rp_filter on Non-public interfaces(eth0,eth1,lo)
        Wed Jan 9 17:02:19 UTC 2013 cloud: enable_fwding = 1
        Wed Jan 9 17:02:19 UTC 2013 enable_fwding = 1

        and /var/log/auth.log in attachments

        + catalina.out and management-server.log from CS host

        Strange, but I do not see anything in the logs to install VPN connection.

        Show
        Richard Shevel added a comment - on VR (r-288-VM) /var/log/messages: Jan 9 17:06:50 r-288-VM cloud: vpc_guestnw.sh: Create network on interface eth2, gateway 10.3.3.1, network 10.3.3.1/24 Jan 9 17:06:52 r-288-VM cloud: Setting up dnsmasq for network 10.3.3.1/24 Jan 9 17:06:55 r-288-VM cloud: Setting up apache web server for eth2 Jan 9 17:06:55 r-288-VM cloud: Setting up password service for network 10.3.3.1/24, eth eth2 Jan 9 17:06:55 r-288-VM cloud: edithosts: update 02:00:01:28:00:01 10.3.3.53 voronin to hosts Jan 9 17:06:55 r-288-VM cloud: /root/edithosts.sh: setting default router for 10.3.3.53 to 10.3.3.1 cloud.log Wed Jan 9 17:02:00 UTC 2013 Executing cloud-early-config Wed Jan 9 17:02:00 UTC 2013 Detected that we are running inside kvm guest Wed Jan 9 17:02:00 UTC 2013 Patching scripts oldmd5=e1defa60190950fbd3d5e9c15c5b7c28 newmd5=89f718b371578db5f8caa40a1da141f1 Wed Jan 9 17:02:01 UTC 2013 Patching cloud service Wed Jan 9 17:02:02 UTC 2013 Rebooting system since we patched init scripts Wed Jan 9 17:02:17 UTC 2013 Executing cloud-early-config Wed Jan 9 17:02:17 UTC 2013 Detected that we are running inside kvm guest Wed Jan 9 17:02:18 UTC 2013 Patching cloud service Wed Jan 9 17:02:18 UTC 2013 Setting up VPC virtual router system vm Wed Jan 9 17:02:19 UTC 2013 Setting up apache web server for VPC Wed Jan 9 17:02:19 UTC 2013 Enable service dnsmasq = 1 Wed Jan 9 17:02:19 UTC 2013 Enable service haproxy = 1 Wed Jan 9 17:02:19 UTC 2013 Enable service cloud = 0 Wed Jan 9 17:02:19 UTC 2013 cloud: Tuning rp_filter on public interfaces Wed Jan 9 17:02:19 UTC 2013 rpfilter public interfaces : Wed Jan 9 17:02:19 UTC 2013 cloud: disable rp_filter on public interfaces Wed Jan 9 17:02:19 UTC 2013 cloud: Enabling rp_filter on Non-public interfaces(eth0,eth1,lo) Wed Jan 9 17:02:19 UTC 2013 cloud: enable_fwding = 1 Wed Jan 9 17:02:19 UTC 2013 enable_fwding = 1 and /var/log/auth.log in attachments + catalina.out and management-server.log from CS host Strange, but I do not see anything in the logs to install VPN connection.
        Hide
        Richard Shevel added a comment -

        I noticed another oddity
        in VR :
        root@r-288-VM:/var/log# ip a
        1: lo: <LOOPBACK,UP,LOWER_UP> mtu 16436 qdisc noqueue state UNKNOWN
        link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
        inet 127.0.0.1/8 scope host lo
        2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000
        link/ether 0e:00:a9:fe:01:e8 brd ff:ff:ff:ff:ff:ff
        inet 169.254.1.232/16 brd 169.254.255.255 scope global eth0
        3: eth1: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN qlen 1000
        link/ether 06:2c:58:00:00:6d brd ff:ff:ff:ff:ff:ff
        4: eth2: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000
        link/ether 02:00:1b:48:00:02 brd ff:ff:ff:ff:ff:ff
        inet 10.3.3.1/24 brd 10.3.3.255

        but if I look through the web interface, I see :

        NIC 1
        Type
        Traffic Type Control
        Network Name
        Netmask 255.255.0.0
        IP Address 169.254.1.232
        ID 1b61695a-70e7-4667-a3f5-ee6f9dbbbd80
        Network ID f7e55fd4-4bc4-4857-bcc1-a5d7903159ab
        Isolation URI
        Broadcast URI
        NIC 2 (Default)
        Type
        Traffic Type Public
        Network Name
        Netmask 255.255.255.192
        IP Address 77.95.133.141
        ID b20274d3-155e-42b5-afb3-f6f76b35275b
        Network ID 9ba9f56d-4a0c-47b1-91e1-e9592e84f3c2
        Isolation URI vlan://50
        Broadcast URI vlan://50
        NIC 3
        Type Isolated
        Traffic Type Guest
        Network Name test_tier
        Netmask 255.255.255.0
        IP Address 10.3.3.1
        ID e0813f21-83ac-4d87-8c06-9eb534ddba8f
        Network ID bf3ec1b2-4a50-4264-8844-3fb47ccb240a
        Isolation URI vlan://598
        Broadcast URI vlan://598

        After adding the vpn connection, the router lost nic2

        Show
        Richard Shevel added a comment - I noticed another oddity in VR : root@r-288-VM:/var/log# ip a 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 16436 qdisc noqueue state UNKNOWN link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00 inet 127.0.0.1/8 scope host lo 2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000 link/ether 0e:00:a9:fe:01:e8 brd ff:ff:ff:ff:ff:ff inet 169.254.1.232/16 brd 169.254.255.255 scope global eth0 3: eth1: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN qlen 1000 link/ether 06:2c:58:00:00:6d brd ff:ff:ff:ff:ff:ff 4: eth2: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000 link/ether 02:00:1b:48:00:02 brd ff:ff:ff:ff:ff:ff inet 10.3.3.1/24 brd 10.3.3.255 but if I look through the web interface, I see : NIC 1 Type Traffic Type Control Network Name Netmask 255.255.0.0 IP Address 169.254.1.232 ID 1b61695a-70e7-4667-a3f5-ee6f9dbbbd80 Network ID f7e55fd4-4bc4-4857-bcc1-a5d7903159ab Isolation URI Broadcast URI NIC 2 (Default) Type Traffic Type Public Network Name Netmask 255.255.255.192 IP Address 77.95.133.141 ID b20274d3-155e-42b5-afb3-f6f76b35275b Network ID 9ba9f56d-4a0c-47b1-91e1-e9592e84f3c2 Isolation URI vlan://50 Broadcast URI vlan://50 NIC 3 Type Isolated Traffic Type Guest Network Name test_tier Netmask 255.255.255.0 IP Address 10.3.3.1 ID e0813f21-83ac-4d87-8c06-9eb534ddba8f Network ID bf3ec1b2-4a50-4264-8844-3fb47ccb240a Isolation URI vlan://598 Broadcast URI vlan://598 After adding the vpn connection, the router lost nic2
        Hide
        Sheng Yang added a comment -

        Are you using the latest 4.0 branch? This things sounds quite wrong.

        If it's a VPC router, why nic1 is down? That's the public interface.

        And router lost nic2? Never heard about that issue...

        Show
        Sheng Yang added a comment - Are you using the latest 4.0 branch? This things sounds quite wrong. If it's a VPC router, why nic1 is down? That's the public interface. And router lost nic2? Never heard about that issue...
        Hide
        Richard Shevel added a comment -

        i'm using :
        cloud-python-4.0.1-0.11.el6.4.0.1.x86_64
        cloud-aws-api-4.0.1-0.11.el6.4.0.1.x86_64
        cloud-scripts-4.0.1-0.11.el6.4.0.1.x86_64
        cloud-deps-4.0.1-0.11.el6.4.0.1.x86_64
        cloud-client-ui-4.0.1-0.11.el6.4.0.1.x86_64
        cloud-utils-4.0.1-0.11.el6.4.0.1.x86_64
        cloud-server-4.0.1-0.11.el6.4.0.1.x86_64
        cloud-client-4.0.1-0.11.el6.4.0.1.x86_64
        cloud-core-4.0.1-0.11.el6.4.0.1.x86_64
        cloud-setup-4.0.1-0.11.el6.4.0.1.x86_64
        cloud-usage-4.0.1-0.11.el6.4.0.1.x86_64

        from cloudstack jenkins

        I also do not understand why the public interface down
        in the web interface there is a record that has a public interface(nic2), but on the VR public interface down. It's looks like a bug, maybe VPN connection can therefore not be added?

        Show
        Richard Shevel added a comment - i'm using : cloud-python-4.0.1-0.11.el6.4.0.1.x86_64 cloud-aws-api-4.0.1-0.11.el6.4.0.1.x86_64 cloud-scripts-4.0.1-0.11.el6.4.0.1.x86_64 cloud-deps-4.0.1-0.11.el6.4.0.1.x86_64 cloud-client-ui-4.0.1-0.11.el6.4.0.1.x86_64 cloud-utils-4.0.1-0.11.el6.4.0.1.x86_64 cloud-server-4.0.1-0.11.el6.4.0.1.x86_64 cloud-client-4.0.1-0.11.el6.4.0.1.x86_64 cloud-core-4.0.1-0.11.el6.4.0.1.x86_64 cloud-setup-4.0.1-0.11.el6.4.0.1.x86_64 cloud-usage-4.0.1-0.11.el6.4.0.1.x86_64 from cloudstack jenkins I also do not understand why the public interface down in the web interface there is a record that has a public interface(nic2), but on the VR public interface down. It's looks like a bug, maybe VPN connection can therefore not be added?
        Hide
        Sheng Yang added a comment -

        If public interface is down, VPC cannot communicate with outside, then no VPN connection can be established of course. It's very serious VPC bug.

        I checked the http://jenkins.cloudstack.org:8080/, the last build of 4.0.1 is almost 1 month ago.

        Could you try to get a newer version to check if the issue is still there?

        Show
        Sheng Yang added a comment - If public interface is down, VPC cannot communicate with outside, then no VPN connection can be established of course. It's very serious VPC bug. I checked the http://jenkins.cloudstack.org:8080/ , the last build of 4.0.1 is almost 1 month ago. Could you try to get a newer version to check if the issue is still there?
        Hide
        Richard Shevel added a comment -

        Сan be initiated creation a new build 4.0.1 in jenkins or do I have to create the CS4.0.1 build by himself?
        I can not find a newer version 4.0.1 for RHEL.

        Show
        Richard Shevel added a comment - Сan be initiated creation a new build 4.0.1 in jenkins or do I have to create the CS4.0.1 build by himself? I can not find a newer version 4.0.1 for RHEL.
        Hide
        David Nalley added a comment -

        I just kicked one off for you.
        IIRC it will take about 30 minutes to finish.

        Show
        David Nalley added a comment - I just kicked one off for you. IIRC it will take about 30 minutes to finish.
        Hide
        Richard Shevel added a comment -

        Thank you very much, colleagues, once the build is complete, I will try start update and again create VPC/VPN Connection

        Show
        Richard Shevel added a comment - Thank you very much, colleagues, once the build is complete, I will try start update and again create VPC/VPN Connection
        Hide
        Richard Shevel added a comment -

        I updated to the version 4.0.1-13.

        After VPC was restarted and look into VR :

        root@r-290-VM:~# ip a
        1: lo: <LOOPBACK,UP,LOWER_UP> mtu 16436 qdisc noqueue state UNKNOWN
        link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
        inet 127.0.0.1/8 scope host lo
        2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000
        link/ether 0e:00:a9:fe:03:4f brd ff:ff:ff:ff:ff:ff
        inet 169.254.3.79/16 brd 169.254.255.255 scope global eth0
        3: eth1: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN qlen 1000
        link/ether 06:cd:12:00:00:6d brd ff:ff:ff:ff:ff:ff
        4: eth2: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000
        link/ether 02:00:17:50:00:03 brd ff:ff:ff:ff:ff:ff
        inet 10.3.3.1/24 brd 10.3.3.255 scope global eth2

        But, If i look at the web interface, i see
        NIC 1
        Type
        Traffic Type Control
        Network Name
        Netmask 255.255.0.0
        IP Address 169.254.3.79
        ID 4e4d89ff-0043-4e04-80d7-a169f6f1b7f8
        Network ID f7e55fd4-4bc4-4857-bcc1-a5d7903159ab
        Isolation URI
        Broadcast URI
        NIC 2 (Default)
        Type
        Traffic Type Public
        Network Name
        Netmask 255.255.255.192
        IP Address 77.95.133.141
        ID 5f54cd44-ca07-4112-bef0-73616451104c
        Network ID 9ba9f56d-4a0c-47b1-91e1-e9592e84f3c2
        Isolation URI vlan://50
        Broadcast URI vlan://50
        NIC 3
        Type Isolated
        Traffic Type Guest
        Network Name test_tier
        Netmask 255.255.255.0
        IP Address 10.3.3.1
        ID 17a4fb14-ce21-445e-99f5-06356ef29ea7
        Network ID bf3ec1b2-4a50-4264-8844-3fb47ccb240a
        Isolation URI vlan://598
        Broadcast URI vlan://598

        Interface with the public ip is in the down state.
        In my problem somewhere on the side of VR.

        if i cheked /var/log/auth.log in VR i see :
        Jan 9 21:46:26 r-290-VM sshd[1654]: pam_unix(sshd:session): session closed for user root
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/echo 1 Table_eth1
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip rule add fwmark 1 table Table_eth1
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush table Table_eth1
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush cache
        Jan 9 21:46:27 r-290-VM sshd[1699]: Accepted publickey for root from 169.254.0.1 port 38308 ssh2
        Jan 9 21:46:27 r-290-VM sshd[1699]: pam_unix(sshd:session): session opened for user root by (uid=0)
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip link show ethnull
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip addr add dev ethnull 77.95.133.141/26 brd +
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables-save -t mangle
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -A PREROUTING -i ethnull -m state --state NEW -j CONNMARK --set-mark null
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add 77.95.133.128/26 dev ethnull table Table_ethnull proto static
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add default via 77.95.133.129 table Table_ethnull proto static
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route flush cache
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add default via 77.95.133.129
        Jan 9 21:46:27 r-290-VM sshd[1699]: Received disconnect from 169.254.0.1: 11: disconnected by user
        Jan 9 21:46:27 r-290-VM sshd[1699]: pam_unix(sshd:session): session closed for user root
        Jan 9 21:46:27 r-290-VM sshd[1743]: Accepted publickey for root from 169.254.0.1 port 38309 ssh2
        Jan 9 21:46:27 r-290-VM sshd[1743]: pam_unix(sshd:session): session opened for user root by (uid=0)
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -D FORWARD -s 10.3.3.0/24 ! -d 10.3.3.0/24 -j ACCEPT
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -A FORWARD -s 10.3.3.0/24 ! -d 10.3.3.0/24 -j ACCEPT
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t nat -D POSTROUTING -j SNAT -o eth2 --to-source 77.95.133.141
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t nat -A POSTROUTING -j SNAT -o eth2 --to-source 77.95.133.141
        Jan 9 21:46:27 r-290-VM sshd[1743]: Received disconnect from 169.254.0.1: 11: disconnected by user
        Jan 9 21:46:27 r-290-VM sshd[1743]: pam_unix(sshd:session): session closed for user root
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/echo 2 Table_eth2
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip rule add fwmark 2 table Table_eth2
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush table Table_eth2
        Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush cache
        Jan 9 21:46:28 r-290-VM sshd[1795]: Accepted publickey for root from 169.254.0.1 port 38310 ssh2
        Jan 9 21:46:28 r-290-VM sshd[1795]: pam_unix(sshd:session): session opened for user root by (uid=0)
        Jan 9 21:46:28 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip addr add dev eth2 10.3.3.1/24 brd +
        Jan 9 21:46:28 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip link set eth2 up
        Jan 9 21:46:28 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/usr/bin/arping -c 3 -I eth2 -A -U -s 10.3.3.1 10.3.3.1
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add 10.3.3.0/24 dev eth2 table Table_eth2 proto static
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -D PREROUTING -i eth2 -m state --state ESTABLISHED,RELATED -j CONNMARK --restore-mark
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t nat -D POSTROUTING -s 10.3.3.0/24 -o eth2 -j SNAT --to-source 10.3.3.1
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -A PREROUTING -i eth2 -m state --state ESTABLISHED,RELATED -j CONNMARK --restore-mark
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t nat -A POSTROUTING -s 10.3.3.0/24 -o eth2 -j SNAT --to-source 10.3.3.1
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -F ACL_OUTBOUND_eth2
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -D PREROUTING -m state --state NEW -i eth2 -s 10.3.3.0/24 ! -d 10.3.3.1 -j ACL_OUTBOUND_eth2
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -X ACL_OUTBOUND_eth2
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -F ACL_INBOUND_eth2
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -D FORWARD -o eth2 -d 10.3.3.0/24 -j ACL_INBOUND_eth2
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -X ACL_INBOUND_eth2
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -N ACL_OUTBOUND_eth2
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -A ACL_OUTBOUND_eth2 -j ACCEPT
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -A PREROUTING -m state --state NEW -i eth2 -s 10.3.3.0/24 ! -d 10.3.3.1 -j ACL_OUTBOUND_eth2
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -N ACL_INBOUND_eth2
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -A ACL_INBOUND_eth2 -j DROP
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -A FORWARD -o eth2 -d 10.3.3.0/24 -j ACL_INBOUND_eth2
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -D INPUT -i eth2 -p udp -m udp --dport 67 -j ACCEPT
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -D INPUT -i eth2 -d 10.3.3.1 -p udp -m udp --dport 53 -j ACCEPT
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -A INPUT -i eth2 -p udp -m udp --dport 67 -j ACCEPT
        Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -A INPUT -i eth2 -d 10.3.3.1 -p udp -m udp --dport 53 -j ACCEPT
        Jan 9 21:46:33 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -D INPUT -i eth2 -d 10.3.3.1 -p tcp -m state --state NEW --dport 80 -j ACCEPT
        Jan 9 21:46:33 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -A INPUT -i eth2 -d 10.3.3.1 -p tcp -m state --state NEW --dport 80 -j ACCEPT
        Jan 9 21:46:33 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -D INPUT -i eth2 -d 10.3.3.1 -p tcp -m state --state NEW --dport 8080 -j ACCEPT
        Jan 9 21:46:33 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -A INPUT -i eth2 -d 10.3.3.1 -p tcp -m state --state NEW --dport 8080 -j ACCEPT
        Jan 9 21:46:33 r-290-VM sshd[1795]: Received disconnect from 169.254.0.1: 11: disconnected by user
        Jan 9 21:46:33 r-290-VM sshd[1795]: pam_unix(sshd:session): session closed for user root
        Jan 9 21:46:33 r-290-VM sshd[1927]: Accepted publickey for root from 169.254.0.1 port 38311 ssh2
        Jan 9 21:46:33 r-290-VM sshd[1927]: pam_unix(sshd:session): session opened for user root by (uid=0)
        Jan 9 21:46:35 r-290-VM sshd[1927]: Received disconnect from 169.254.0.1: 11: disconnected by user

        after this public interface down

        why the script executes the "/sbin/ip addr add dev ethnull 77.95.133.141/26 brd +" ?? I think it look like a bug! obviously needs to be "/sbin/ip addr add dev eth1 77.95.133.141/26 brd +"

        Ready to provide any logs.

        Show
        Richard Shevel added a comment - I updated to the version 4.0.1-13. After VPC was restarted and look into VR : root@r-290-VM:~# ip a 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 16436 qdisc noqueue state UNKNOWN link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00 inet 127.0.0.1/8 scope host lo 2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000 link/ether 0e:00:a9:fe:03:4f brd ff:ff:ff:ff:ff:ff inet 169.254.3.79/16 brd 169.254.255.255 scope global eth0 3: eth1: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN qlen 1000 link/ether 06:cd:12:00:00:6d brd ff:ff:ff:ff:ff:ff 4: eth2: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000 link/ether 02:00:17:50:00:03 brd ff:ff:ff:ff:ff:ff inet 10.3.3.1/24 brd 10.3.3.255 scope global eth2 But, If i look at the web interface, i see NIC 1 Type Traffic Type Control Network Name Netmask 255.255.0.0 IP Address 169.254.3.79 ID 4e4d89ff-0043-4e04-80d7-a169f6f1b7f8 Network ID f7e55fd4-4bc4-4857-bcc1-a5d7903159ab Isolation URI Broadcast URI NIC 2 (Default) Type Traffic Type Public Network Name Netmask 255.255.255.192 IP Address 77.95.133.141 ID 5f54cd44-ca07-4112-bef0-73616451104c Network ID 9ba9f56d-4a0c-47b1-91e1-e9592e84f3c2 Isolation URI vlan://50 Broadcast URI vlan://50 NIC 3 Type Isolated Traffic Type Guest Network Name test_tier Netmask 255.255.255.0 IP Address 10.3.3.1 ID 17a4fb14-ce21-445e-99f5-06356ef29ea7 Network ID bf3ec1b2-4a50-4264-8844-3fb47ccb240a Isolation URI vlan://598 Broadcast URI vlan://598 Interface with the public ip is in the down state. In my problem somewhere on the side of VR. if i cheked /var/log/auth.log in VR i see : Jan 9 21:46:26 r-290-VM sshd [1654] : pam_unix(sshd:session): session closed for user root Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/echo 1 Table_eth1 Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip rule add fwmark 1 table Table_eth1 Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush table Table_eth1 Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush cache Jan 9 21:46:27 r-290-VM sshd [1699] : Accepted publickey for root from 169.254.0.1 port 38308 ssh2 Jan 9 21:46:27 r-290-VM sshd [1699] : pam_unix(sshd:session): session opened for user root by (uid=0) Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip link show ethnull Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip addr add dev ethnull 77.95.133.141/26 brd + Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables-save -t mangle Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -A PREROUTING -i ethnull -m state --state NEW -j CONNMARK --set-mark null Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add 77.95.133.128/26 dev ethnull table Table_ethnull proto static Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add default via 77.95.133.129 table Table_ethnull proto static Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route flush cache Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add default via 77.95.133.129 Jan 9 21:46:27 r-290-VM sshd [1699] : Received disconnect from 169.254.0.1: 11: disconnected by user Jan 9 21:46:27 r-290-VM sshd [1699] : pam_unix(sshd:session): session closed for user root Jan 9 21:46:27 r-290-VM sshd [1743] : Accepted publickey for root from 169.254.0.1 port 38309 ssh2 Jan 9 21:46:27 r-290-VM sshd [1743] : pam_unix(sshd:session): session opened for user root by (uid=0) Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -D FORWARD -s 10.3.3.0/24 ! -d 10.3.3.0/24 -j ACCEPT Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -A FORWARD -s 10.3.3.0/24 ! -d 10.3.3.0/24 -j ACCEPT Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t nat -D POSTROUTING -j SNAT -o eth2 --to-source 77.95.133.141 Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t nat -A POSTROUTING -j SNAT -o eth2 --to-source 77.95.133.141 Jan 9 21:46:27 r-290-VM sshd [1743] : Received disconnect from 169.254.0.1: 11: disconnected by user Jan 9 21:46:27 r-290-VM sshd [1743] : pam_unix(sshd:session): session closed for user root Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/echo 2 Table_eth2 Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip rule add fwmark 2 table Table_eth2 Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush table Table_eth2 Jan 9 21:46:27 r-290-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush cache Jan 9 21:46:28 r-290-VM sshd [1795] : Accepted publickey for root from 169.254.0.1 port 38310 ssh2 Jan 9 21:46:28 r-290-VM sshd [1795] : pam_unix(sshd:session): session opened for user root by (uid=0) Jan 9 21:46:28 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip addr add dev eth2 10.3.3.1/24 brd + Jan 9 21:46:28 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip link set eth2 up Jan 9 21:46:28 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/usr/bin/arping -c 3 -I eth2 -A -U -s 10.3.3.1 10.3.3.1 Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add 10.3.3.0/24 dev eth2 table Table_eth2 proto static Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -D PREROUTING -i eth2 -m state --state ESTABLISHED,RELATED -j CONNMARK --restore-mark Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t nat -D POSTROUTING -s 10.3.3.0/24 -o eth2 -j SNAT --to-source 10.3.3.1 Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -A PREROUTING -i eth2 -m state --state ESTABLISHED,RELATED -j CONNMARK --restore-mark Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t nat -A POSTROUTING -s 10.3.3.0/24 -o eth2 -j SNAT --to-source 10.3.3.1 Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -F ACL_OUTBOUND_eth2 Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -D PREROUTING -m state --state NEW -i eth2 -s 10.3.3.0/24 ! -d 10.3.3.1 -j ACL_OUTBOUND_eth2 Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -X ACL_OUTBOUND_eth2 Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -F ACL_INBOUND_eth2 Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -D FORWARD -o eth2 -d 10.3.3.0/24 -j ACL_INBOUND_eth2 Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -X ACL_INBOUND_eth2 Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -N ACL_OUTBOUND_eth2 Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -A ACL_OUTBOUND_eth2 -j ACCEPT Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -A PREROUTING -m state --state NEW -i eth2 -s 10.3.3.0/24 ! -d 10.3.3.1 -j ACL_OUTBOUND_eth2 Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -N ACL_INBOUND_eth2 Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -A ACL_INBOUND_eth2 -j DROP Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -A FORWARD -o eth2 -d 10.3.3.0/24 -j ACL_INBOUND_eth2 Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -D INPUT -i eth2 -p udp -m udp --dport 67 -j ACCEPT Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -D INPUT -i eth2 -d 10.3.3.1 -p udp -m udp --dport 53 -j ACCEPT Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -A INPUT -i eth2 -p udp -m udp --dport 67 -j ACCEPT Jan 9 21:46:30 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -A INPUT -i eth2 -d 10.3.3.1 -p udp -m udp --dport 53 -j ACCEPT Jan 9 21:46:33 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -D INPUT -i eth2 -d 10.3.3.1 -p tcp -m state --state NEW --dport 80 -j ACCEPT Jan 9 21:46:33 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -A INPUT -i eth2 -d 10.3.3.1 -p tcp -m state --state NEW --dport 80 -j ACCEPT Jan 9 21:46:33 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -D INPUT -i eth2 -d 10.3.3.1 -p tcp -m state --state NEW --dport 8080 -j ACCEPT Jan 9 21:46:33 r-290-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -A INPUT -i eth2 -d 10.3.3.1 -p tcp -m state --state NEW --dport 8080 -j ACCEPT Jan 9 21:46:33 r-290-VM sshd [1795] : Received disconnect from 169.254.0.1: 11: disconnected by user Jan 9 21:46:33 r-290-VM sshd [1795] : pam_unix(sshd:session): session closed for user root Jan 9 21:46:33 r-290-VM sshd [1927] : Accepted publickey for root from 169.254.0.1 port 38311 ssh2 Jan 9 21:46:33 r-290-VM sshd [1927] : pam_unix(sshd:session): session opened for user root by (uid=0) Jan 9 21:46:35 r-290-VM sshd [1927] : Received disconnect from 169.254.0.1: 11: disconnected by user after this public interface down why the script executes the "/sbin/ip addr add dev ethnull 77.95.133.141/26 brd +" ?? I think it look like a bug! obviously needs to be "/sbin/ip addr add dev eth1 77.95.133.141/26 brd +" Ready to provide any logs.
        Hide
        Sheng Yang added a comment -

        It's obvious something goes wrong when programming the router.

        Please provide the mgmt server log.

        Thank you!

        Show
        Sheng Yang added a comment - It's obvious something goes wrong when programming the router. Please provide the mgmt server log. Thank you!
        Hide
        Richard Shevel added a comment -

        attached management-server_after_upgrade.zip

        Show
        Richard Shevel added a comment - attached management-server_after_upgrade.zip
        Hide
        Sheng Yang added a comment -

        Hi Richard,

        Have you upgrade the kvm agent as well?

        And you also need to restart router for upgrading to sync with cloudstack mgmt server.

        Show
        Sheng Yang added a comment - Hi Richard, Have you upgrade the kvm agent as well? And you also need to restart router for upgrading to sync with cloudstack mgmt server.
        Hide
        Richard Shevel added a comment -

        I updated MGNT server and KVM agent sequentially and restarted the VPC router immediately after the new CS installed.

        Show
        Richard Shevel added a comment - I updated MGNT server and KVM agent sequentially and restarted the VPC router immediately after the new CS installed.
        Hide
        Sheng Yang added a comment -

        The version of scripts in the router is wrong.

        2013-01-10 02:03:06,939 DEBUG [agent.transport.Request] (AgentManager-Handler-14:null) Seq 3-2146107506: Processing: { Ans: , MgmtId: 52239887788, via: 3, Ver: v1, Flags: 100, [{"Answer":{"result":false,"details":"Configure site to site VPN failed due to bash: /opt/cloud/bin/ipsectunnel: No such file or directory","wait":0}}] }

        Have you updated KVM agent along with the systemvm.iso file?

        Show
        Sheng Yang added a comment - The version of scripts in the router is wrong. 2013-01-10 02:03:06,939 DEBUG [agent.transport.Request] (AgentManager-Handler-14:null) Seq 3-2146107506: Processing: { Ans: , MgmtId: 52239887788, via: 3, Ver: v1, Flags: 100, [{"Answer":{"result":false,"details":"Configure site to site VPN failed due to bash: /opt/cloud/bin/ipsectunnel: No such file or directory","wait":0}}] } Have you updated KVM agent along with the systemvm.iso file?
        Hide
        edison su added a comment -

        If cloud-agent*.rpm is upgraded, then system vm iso should be upgraded also.

        Show
        edison su added a comment - If cloud-agent*.rpm is upgraded, then system vm iso should be upgraded also.
        Hide
        Richard Shevel added a comment -

        I've updated all the RPM on KVM hosts and CS host.

        I spent the next experiment:
        1. Created new Domain
        2. Loged in to new Domain
        3. Created new VPC (with 10.4.4.0/24 network)
        4. Create new tier (10.4.4.1 gateway)
        5. entered as administrator and look for new VR:

        State Running
        Network ID
        Public IP Address 77.95.133.142
        Guest IP Address
        Link Local IP Adddress 169.254.1.73
        Host bh620-4.dn.local
        Compute offering System Offering For Software Router
        Network Domain
        Domain test1
        Account test1
        Created 10 Jan 2013 10:27:15
        Redundant Router No
        Redundant state
        VPC ID 518b7f87-bbf4-405b-a90a-9d0dfaf11271

        5. entered in VR :
        root@r-292-VM:~# ip a
        1: lo: <LOOPBACK,UP,LOWER_UP> mtu 16436 qdisc noqueue state UNKNOWN
        link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
        inet 127.0.0.1/8 scope host lo
        2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000
        link/ether 0e:00:a9:fe:01:49 brd ff:ff:ff:ff:ff:ff
        inet 169.254.1.73/16 brd 169.254.255.255 scope global eth0
        3: eth1: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN qlen 1000
        link/ether 06:bb:92:00:00:6e brd ff:ff:ff:ff:ff:ff
        root@r-292-VM:~#

        if I look at /var/log/auth.log , i see :

        Jan 10 10:28:58 r-292-VM sshd[1586]: pam_unix(sshd:session): session closed for user root
        Jan 10 10:28:58 r-292-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/echo 1 Table_eth1
        Jan 10 10:28:58 r-292-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip rule add fwmark 1 table Table_eth1
        Jan 10 10:28:58 r-292-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush table Table_eth1
        Jan 10 10:28:58 r-292-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush cache
        Jan 10 10:28:58 r-292-VM sshd[1631]: Accepted publickey for root from 169.254.0.1 port 41066 ssh2
        Jan 10 10:28:58 r-292-VM sshd[1631]: pam_unix(sshd:session): session opened for user root by (uid=0)
        Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip link show ethnull
        Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip addr add dev ethnull 77.95.133.142/26 brd +
        Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables-save -t mangle
        Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -A PREROUTING -i ethnull -m state --state NEW -j CONNMARK --set-mark null
        Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add 77.95.133.128/26 dev ethnull table Table_ethnull proto static
        Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add default via 77.95.133.129 table Table_ethnull proto static
        Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route flush cache
        Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route
        Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add default via 77.95.133.129
        Jan 10 10:28:59 r-292-VM sshd[1631]: Received disconnect from 169.254.0.1: 11: disconnected by user
        Jan 10 10:28:59 r-292-VM sshd[1631]: pam_unix(sshd:session): session closed for user root
        Jan 10 10:28:59 r-292-VM sshd[1675]: Accepted publickey for root from 169.254.0.1 port 41067 ssh2

        Once again the value "ethnull"

        maybe the problem is not how much a VPN in the proper formation of the VPC ?? ,

        attached mangmtn log as management-server_after_upgrade2.zip

        Show
        Richard Shevel added a comment - I've updated all the RPM on KVM hosts and CS host. I spent the next experiment: 1. Created new Domain 2. Loged in to new Domain 3. Created new VPC (with 10.4.4.0/24 network) 4. Create new tier (10.4.4.1 gateway) 5. entered as administrator and look for new VR: State Running Network ID Public IP Address 77.95.133.142 Guest IP Address Link Local IP Adddress 169.254.1.73 Host bh620-4.dn.local Compute offering System Offering For Software Router Network Domain Domain test1 Account test1 Created 10 Jan 2013 10:27:15 Redundant Router No Redundant state VPC ID 518b7f87-bbf4-405b-a90a-9d0dfaf11271 5. entered in VR : root@r-292-VM:~# ip a 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 16436 qdisc noqueue state UNKNOWN link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00 inet 127.0.0.1/8 scope host lo 2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000 link/ether 0e:00:a9:fe:01:49 brd ff:ff:ff:ff:ff:ff inet 169.254.1.73/16 brd 169.254.255.255 scope global eth0 3: eth1: <BROADCAST,MULTICAST> mtu 1500 qdisc noop state DOWN qlen 1000 link/ether 06:bb:92:00:00:6e brd ff:ff:ff:ff:ff:ff root@r-292-VM:~# if I look at /var/log/auth.log , i see : Jan 10 10:28:58 r-292-VM sshd [1586] : pam_unix(sshd:session): session closed for user root Jan 10 10:28:58 r-292-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/echo 1 Table_eth1 Jan 10 10:28:58 r-292-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip rule add fwmark 1 table Table_eth1 Jan 10 10:28:58 r-292-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush table Table_eth1 Jan 10 10:28:58 r-292-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush cache Jan 10 10:28:58 r-292-VM sshd [1631] : Accepted publickey for root from 169.254.0.1 port 41066 ssh2 Jan 10 10:28:58 r-292-VM sshd [1631] : pam_unix(sshd:session): session opened for user root by (uid=0) Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip link show ethnull Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip addr add dev ethnull 77.95.133.142/26 brd + Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables-save -t mangle Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -A PREROUTING -i ethnull -m state --state NEW -j CONNMARK --set-mark null Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add 77.95.133.128/26 dev ethnull table Table_ethnull proto static Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add default via 77.95.133.129 table Table_ethnull proto static Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route flush cache Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add default via 77.95.133.129 Jan 10 10:28:59 r-292-VM sshd [1631] : Received disconnect from 169.254.0.1: 11: disconnected by user Jan 10 10:28:59 r-292-VM sshd [1631] : pam_unix(sshd:session): session closed for user root Jan 10 10:28:59 r-292-VM sshd [1675] : Accepted publickey for root from 169.254.0.1 port 41067 ssh2 Once again the value "ethnull" maybe the problem is not how much a VPN in the proper formation of the VPC ?? , attached mangmtn log as management-server_after_upgrade2.zip
        Hide
        Sheng Yang added a comment -

        ethnull has nothing to do with VPN, it's happened before.

        Could you show me /var/log/messages?

        Show
        Sheng Yang added a comment - ethnull has nothing to do with VPN, it's happened before. Could you show me /var/log/messages?
        Hide
        Richard Shevel added a comment -

        Yep, /var/log/messages from VR attached

        Show
        Richard Shevel added a comment - Yep, /var/log/messages from VR attached
        Hide
        Sheng Yang added a comment -

        this message doesn't match r-292-VM. You provided r-4-VM...

        Show
        Sheng Yang added a comment - this message doesn't match r-292-VM. You provided r-4-VM...
        Hide
        Richard Shevel added a comment -

        in the log it says that it is r-292-VM log.
        "r-292-VM kernel: " etc..

        or you want log from "r-4-VM" ?

        Show
        Richard Shevel added a comment - in the log it says that it is r-292-VM log. "r-292-VM kernel: " etc.. or you want log from "r-4-VM" ?
        Hide
        Sheng Yang added a comment -

        oh, sorry, got the wrong log...

        But this log is even more weird... Nothing shows..

        I need to recheck all the logs...

        Show
        Sheng Yang added a comment - oh, sorry, got the wrong log... But this log is even more weird... Nothing shows.. I need to recheck all the logs...
        Hide
        Richard Shevel added a comment -

        i made /var/log archive from r-292-VM and attached him to issue (r-292-vm_log.tar.gz)

        Show
        Richard Shevel added a comment - i made /var/log archive from r-292-VM and attached him to issue (r-292-vm_log.tar.gz)
        Hide
        Sheng Yang added a comment -

        OK, here is what's wrong.

        Jan 10 10:28:59 r-292-VM cloud: vpc_ipassoc.sh:Adding ip 77.95.133.142 on interface ethnull
        Jan 10 10:28:59 r-292-VM cloud: vpc_ipassoc.sh:Add routing 77.95.133.142 on interface ethnull
        Jan 10 10:28:59 r-292-VM cloud: vpc_snat.sh:Added SourceNAT 77.95.133.142 on interface eth2

        But I am failed to match it with mgmt server log.

        I guess it's the result of:

        2013-01-10 14:27:58,720 DEBUG [agent.transport.Request] (Job-Executor-14:job-489) Seq 5-867174260: Sending { Cmd , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 100111, [{"StartCommand":{"vm":{"id":292,"name":"r-292-VM","type":"DomainRouter","
        cpus":1,"speed":500,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"Debian GNU/Linux 5.0 (32-bit)","bootArgs":" vpccidr=10.4.4.0/24 domain=test1vpc dns1=8.8.8.8 dns2=8.8.4.4 template=domP name=r-292-VM eth0ip=169.254.1.73 eth0mask=
        255.255.0.0 type=vpcrouter disable_rp_filter=true","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"vncPassword":"5619bf8c760f7042","params":{},"uuid":"10291b7f-1521-476f-abb1-5eb04ac11b02","disks":[

        {"id":589,"name":"/vg0_md","mountP oint":"c2998ea2-5dbf-4722-bcb6-5dfaa288c33d","path":"c2998ea2-5dbf-4722-bcb6-5dfaa288c33d","size":725811200,"type":"ROOT","storagePoolType":"CLVM","storagePoolUuid":"724141d8-75a9-4033-8209-2ce6a64fe12a","deviceId":0}

        ],"nics":[

        {"deviceId":0,"n etworkRateMbps":-1,"defaultNic":false,"uuid":"224e8e50-649b-44c1-9b63-a55e8bce10cd","ip":"169.254.1.73","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:01:49","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnab led":false}

        ]},"wait":0}},{"check.CheckSshCommand":{"ip":"169.254.1.73","port":3922,"interval":6,"retries":100,"name":"r-292-VM","wait":0}},{"GetDomRVersionCmd":{"accessDetails":

        {"router.ip":"169.254.1.73","router.name":"r-292-VM"}

        ,"wait":0}},{
        },{"PlugNicCommand":{"nic":

        {"deviceId":1,"networkRateMbps":200,"defaultNic":true,"uuid":"f59a35e8-47ef-446a-b99d-0d3e5e79f510","ip":"77.95.133.142","netmask":"255.255.255.192","gateway":"77.95.133.129","mac":"06:bb:92:00:00:6e","dns1":"8.8.8.8 ","dns2":"8.8.4.4","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://50","isolationUri":"vlan://50","isSecurityGroupEnabled":false,"name":"cloudbr1"}

        ,"instanceName":"r-292-VM","wait":0}},{"routing.IpAssocVpcCommand":{"ipAddresses":
        [

        {"accountId":9,"publicIp":"77.95.133.142","sourceNat":true,"add":true,"oneToOneNat":false,"firstIP":false,"vlanId":"50","vlanGateway":"77.95.133.129","vlanNetmask":"255.255.255.192","vifMacAddress":"06:bb:92:00:00:6e","networkRate":200,"traff icType":"Public","networkName":"cloudbr1"}

        ],"accessDetails":

        {"router.guest.ip":"77.95.133.142","zone.network.type":"Advanced","router.ip":"169.254.1.73","router.name":"r-292-VM"}

        ,"wait":0}},{"routing.SetSourceNatCommand":{"ipAddress":

        {"account Id":9,"publicIp":"77.95.133.142","sourceNat":true,"add":true,"oneToOneNat":false,"firstIP":false,"vlanId":"50","vlanGateway":"77.95.133.129","vlanNetmask":"255.255.255.192","vifMacAddress":"06:bb:92:00:00:6e","networkRate":200,"trafficType":"P ublic","networkName":"cloudbr1"}

        ,"add":true,"accessDetails":

        {"zone.network.type":"Advanced","router.ip":"169.254.1.73","router.name":"r-292-VM"}

        ,"wait":0}},{}] }

        but this command seems fine to me.

        Hi Richard,

        Could you restart the VPC router, then after it's complete, attached the latest log?(both mgmt log and /var/log/messages in router)

        Thank you!

        Show
        Sheng Yang added a comment - OK, here is what's wrong. Jan 10 10:28:59 r-292-VM cloud: vpc_ipassoc.sh:Adding ip 77.95.133.142 on interface ethnull Jan 10 10:28:59 r-292-VM cloud: vpc_ipassoc.sh:Add routing 77.95.133.142 on interface ethnull Jan 10 10:28:59 r-292-VM cloud: vpc_snat.sh:Added SourceNAT 77.95.133.142 on interface eth2 But I am failed to match it with mgmt server log. I guess it's the result of: 2013-01-10 14:27:58,720 DEBUG [agent.transport.Request] (Job-Executor-14:job-489) Seq 5-867174260: Sending { Cmd , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 100111, [{"StartCommand":{"vm":{"id":292,"name":"r-292-VM","type":"DomainRouter"," cpus":1,"speed":500,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"Debian GNU/Linux 5.0 (32-bit)","bootArgs":" vpccidr=10.4.4.0/24 domain=test1vpc dns1=8.8.8.8 dns2=8.8.4.4 template=domP name=r-292-VM eth0ip=169.254.1.73 eth0mask= 255.255.0.0 type=vpcrouter disable_rp_filter=true","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"vncPassword":"5619bf8c760f7042","params":{},"uuid":"10291b7f-1521-476f-abb1-5eb04ac11b02","disks":[ {"id":589,"name":"/vg0_md","mountP oint":"c2998ea2-5dbf-4722-bcb6-5dfaa288c33d","path":"c2998ea2-5dbf-4722-bcb6-5dfaa288c33d","size":725811200,"type":"ROOT","storagePoolType":"CLVM","storagePoolUuid":"724141d8-75a9-4033-8209-2ce6a64fe12a","deviceId":0} ],"nics":[ {"deviceId":0,"n etworkRateMbps":-1,"defaultNic":false,"uuid":"224e8e50-649b-44c1-9b63-a55e8bce10cd","ip":"169.254.1.73","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:01:49","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnab led":false} ]},"wait":0}},{"check.CheckSshCommand":{"ip":"169.254.1.73","port":3922,"interval":6,"retries":100,"name":"r-292-VM","wait":0}},{"GetDomRVersionCmd":{"accessDetails": {"router.ip":"169.254.1.73","router.name":"r-292-VM"} ,"wait":0}},{ },{"PlugNicCommand":{"nic": {"deviceId":1,"networkRateMbps":200,"defaultNic":true,"uuid":"f59a35e8-47ef-446a-b99d-0d3e5e79f510","ip":"77.95.133.142","netmask":"255.255.255.192","gateway":"77.95.133.129","mac":"06:bb:92:00:00:6e","dns1":"8.8.8.8 ","dns2":"8.8.4.4","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://50","isolationUri":"vlan://50","isSecurityGroupEnabled":false,"name":"cloudbr1"} ,"instanceName":"r-292-VM","wait":0}},{"routing.IpAssocVpcCommand":{"ipAddresses": [ {"accountId":9,"publicIp":"77.95.133.142","sourceNat":true,"add":true,"oneToOneNat":false,"firstIP":false,"vlanId":"50","vlanGateway":"77.95.133.129","vlanNetmask":"255.255.255.192","vifMacAddress":"06:bb:92:00:00:6e","networkRate":200,"traff icType":"Public","networkName":"cloudbr1"} ],"accessDetails": {"router.guest.ip":"77.95.133.142","zone.network.type":"Advanced","router.ip":"169.254.1.73","router.name":"r-292-VM"} ,"wait":0}},{"routing.SetSourceNatCommand":{"ipAddress": {"account Id":9,"publicIp":"77.95.133.142","sourceNat":true,"add":true,"oneToOneNat":false,"firstIP":false,"vlanId":"50","vlanGateway":"77.95.133.129","vlanNetmask":"255.255.255.192","vifMacAddress":"06:bb:92:00:00:6e","networkRate":200,"trafficType":"P ublic","networkName":"cloudbr1"} ,"add":true,"accessDetails": {"zone.network.type":"Advanced","router.ip":"169.254.1.73","router.name":"r-292-VM"} ,"wait":0}},{}] } but this command seems fine to me. Hi Richard, Could you restart the VPC router, then after it's complete, attached the latest log?(both mgmt log and /var/log/messages in router) Thank you!
        Hide
        Richard Shevel added a comment -

        I restarted the VPC and attached both log(mgmt log and /var/log/messages in router) file : after_restart_VPC.zip

        Show
        Richard Shevel added a comment - I restarted the VPC and attached both log(mgmt log and /var/log/messages in router) file : after_restart_VPC.zip
        Hide
        Sheng Yang added a comment -

        Got it. Mgmt server works well as far as I can tell.

        Still very likely the scripts in the VR is wrong, or have bugs.

        I would try to confirm this bug in our lab.

        Show
        Sheng Yang added a comment - Got it. Mgmt server works well as far as I can tell. Still very likely the scripts in the VR is wrong, or have bugs. I would try to confirm this bug in our lab.
        Hide
        Richard Shevel added a comment -

        Ok, thanks.

        P.S.
        This error occurs only when creating VPC
        If i created a normal guest network(without VPC), this problem is not observed.
        But I need s2s VPN so i have to create VPC =(

        Show
        Richard Shevel added a comment - Ok, thanks. P.S. This error occurs only when creating VPC If i created a normal guest network(without VPC), this problem is not observed. But I need s2s VPN so i have to create VPC =(
        Hide
        Abhinav Roy added a comment -

        Hi Sheng,

        I tested this feature in my environment but with the same customer VPN gateway details as used by Richard and here are my findings :-

        VPC VR logs :-
        ==========================================================

        1. root@r-9-VM:/var/log# ifconfig
        eth0 Link encap:Ethernet HWaddr 0e:00:a9:fe:00:04
        inet addr:169.254.0.4 Bcast:169.254.255.255 Mask:255.255.0.0
        UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
        RX packets:1023 errors:0 dropped:0 overruns:0 frame:0
        TX packets:668 errors:0 dropped:0 overruns:0 carrier:0
        collisions:0 txqueuelen:1000
        RX bytes:105813 (103.3 KiB) TX bytes:175004 (170.9 KiB)

        eth1 Link encap:Ethernet HWaddr 06:3c:62:00:00:10
        inet addr:10.102.195.74 Bcast:10.102.195.255 Mask:255.255.252.0
        UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
        RX packets:53518 errors:0 dropped:0 overruns:0 frame:0
        TX packets:2 errors:0 dropped:0 overruns:0 carrier:0
        collisions:0 txqueuelen:1000
        RX bytes:3766292 (3.5 MiB) TX bytes:84 (84.0 B)

        lo Link encap:Local Loopback
        inet addr:127.0.0.1 Mask:255.0.0.0
        UP LOOPBACK RUNNING MTU:16436 Metric:1
        RX packets:6 errors:0 dropped:0 overruns:0 frame:0
        TX packets:6 errors:0 dropped:0 overruns:0 carrier:0
        collisions:0 txqueuelen:0
        RX bytes:414 (414.0 B) TX bytes:414 (414.0 B)

        2. Nics.

        NIC 1
        Type
        Traffic Type Control
        Network Name
        Netmask 255.255.0.0
        IP Address 169.254.0.4
        ID a1b03f69-3606-486e-a7d6-504878bf6184
        Network ID 7a44608b-60a0-488a-b2db-2187fa346ef0
        Isolation URI
        Broadcast URI

        NIC 2 (Default)
        Type
        Traffic Type Public
        Network Name
        Netmask 255.255.252.0
        IP Address 10.102.195.74
        ID b3d3de74-1f6a-4f81-9f27-7d23682ca948
        Network ID 18d5e28a-ac84-4ed1-87a4-65346f4660f3
        Isolation URI vlan://untagged
        Broadcast URI vlan://untagged

        Here we see that the NIC-2 which is Eth1 has the public IP.

        But lets see in the cloud.log, here Eth1 is not treated as the public interface

        Jan 16 10:29:11 r-9-VM sshd[1427]: Server listening on 169.254.0.4 port 3922.
        Jan 16 10:29:11 r-9-VM sshd[1427]: error: Bind to port 3922 on 169.254.0.4 failed: Address already in use.
        Jan 16 10:29:20 r-9-VM sshd[1612]: Did not receive identification string from 169.254.0.1
        Jan 16 10:29:20 r-9-VM sshd[1613]: Accepted publickey for root from 169.254.0.1 port 59845 ssh2
        Wed Jan 16 10:28:51 UTC 2013 Executing cloud-early-config
        Wed Jan 16 10:28:51 UTC 2013 Detected that we are running inside kvm guest
        Wed Jan 16 10:28:51 UTC 2013 Patching scripts oldmd5=e1defa60190950fbd3d5e9c15c5b7c28 newmd5=89f718b371578db5f8caa40a1da141f1
        Wed Jan 16 10:28:51 UTC 2013 Patching cloud service
        Wed Jan 16 10:28:53 UTC 2013 Rebooting system since we patched init scripts
        Wed Jan 16 10:29:09 UTC 2013 Executing cloud-early-config
        Wed Jan 16 10:29:09 UTC 2013 Detected that we are running inside kvm guest
        Wed Jan 16 10:29:09 UTC 2013 Patching cloud service
        Wed Jan 16 10:29:11 UTC 2013 Setting up VPC virtual router system vm
        Wed Jan 16 10:29:11 UTC 2013 Setting up apache web server for VPC
        Wed Jan 16 10:29:11 UTC 2013 Enable service dnsmasq = 1
        Wed Jan 16 10:29:11 UTC 2013 Enable service haproxy = 1
        Wed Jan 16 10:29:11 UTC 2013 Enable service cloud = 0
        Wed Jan 16 10:29:11 UTC 2013 cloud: Tuning rp_filter on public interfaces
        Wed Jan 16 10:29:11 UTC 2013 rpfilter public interfaces :
        Wed Jan 16 10:29:11 UTC 2013 cloud: disable rp_filter on public interfaces
        Wed Jan 16 10:29:11 UTC 2013 cloud: Enabling rp_filter on Non-public interfaces(eth0,eth1,lo) ----------------------------------->>>> Here we see that it treats eth1 also as non-public interface
        Wed Jan 16 10:29:11 UTC 2013 cloud: enable_fwding = 1
        Wed Jan 16 10:29:11 UTC 2013 enable_fwding = 1

        4. Auth.log

        Jan 16 10:29:11 r-9-VM sshd[1427]: Server listening on 169.254.0.4 port 3922.
        Jan 16 10:29:11 r-9-VM sshd[1427]: error: Bind to port 3922 on 169.254.0.4 failed: Address already in use.
        Jan 16 10:29:20 r-9-VM sshd[1612]: Did not receive identification string from 169.254.0.1
        Jan 16 10:29:20 r-9-VM sshd[1613]: Accepted publickey for root from 169.254.0.1 port 59845 ssh2
        Jan 16 10:29:20 r-9-VM sshd[1613]: pam_unix(sshd:session): session opened for user root by (uid=0)
        Jan 16 10:29:20 r-9-VM sshd[1613]: Received disconnect from 169.254.0.1: 11: disconnected by user
        Jan 16 10:29:20 r-9-VM sshd[1613]: pam_unix(sshd:session): session closed for user root
        Jan 16 10:29:20 r-9-VM sshd[1618]: Accepted publickey for root from 169.254.0.1 port 59846 ssh2
        Jan 16 10:29:20 r-9-VM sshd[1618]: pam_unix(sshd:session): session opened for user root by (uid=0)
        Jan 16 10:29:20 r-9-VM sshd[1618]: Received disconnect from 169.254.0.1: 11: disconnected by user
        Jan 16 10:29:20 r-9-VM sshd[1618]: pam_unix(sshd:session): session closed for user root
        Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/echo 1 Table_eth1
        Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip rule add fwmark 1 table Table_eth1
        Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush table Table_eth1
        Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush cache
        Jan 16 10:29:20 r-9-VM sshd[1648]: Accepted publickey for root from 169.254.0.1 port 59847 ssh2
        Jan 16 10:29:20 r-9-VM sshd[1648]: pam_unix(sshd:session): session opened for user root by (uid=0)
        Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip link show eth1
        Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip addr add dev eth1 10.102.195.74/22 brd +
        Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip link set eth1 up
        Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/usr/bin/arping -c 3 -I eth1 -A -U -s 10.102.195.74 10.102.195.74
        Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables-save -t mangle
        Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -A PREROUTING -i eth1 -m state --state NEW -j CONNMARK --set-mark 1
        Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add 10.102.192.0/22 dev eth1 table Table_eth1 proto static
        Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add default via 10.102.192.1 table Table_eth1 proto static
        Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route flush cache
        Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route
        Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add default via 10.102.192.1
        Jan 16 10:29:22 r-9-VM sshd[1648]: Received disconnect from 169.254.0.1: 11: disconnected by user
        Jan 16 10:29:22 r-9-VM sshd[1648]: pam_unix(sshd:session): session closed for user root
        Jan 16 10:29:23 r-9-VM sshd[1708]: Accepted publickey for root from 169.254.0.1 port 59848 ssh2
        Jan 16 10:29:23 r-9-VM sshd[1708]: pam_unix(sshd:session): session opened for user root by (uid=0)
        Jan 16 10:29:23 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -D FORWARD -s 10.1.1.1/16 ! -d 10.1.1.1/16 -j ACCEPT
        Jan 16 10:29:23 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -A FORWARD -s 10.1.1.1/16 ! -d 10.1.1.1/16 -j ACCEPT
        Jan 16 10:29:23 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t nat -D POSTROUTING -j SNAT -o eth1 --to-source 10.102.195.74
        Jan 16 10:29:23 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t nat -A POSTROUTING -j SNAT -o eth1 --to-source 10.102.195.74
        Jan 16 10:29:23 r-9-VM sshd[1708]: Received disconnect from 169.254.0.1: 11: disconnected by user
        Jan 16 10:29:23 r-9-VM sshd[1708]: pam_unix(sshd:session): session closed for user root
        Jan 16 10:29:23 r-9-VM sshd[1739]: Accepted publickey for root from 169.254.0.1 port 59849 ssh2
        Jan 16 10:29:23 r-9-VM sshd[1739]: pam_unix(sshd:session): session opened for user root by (uid=0)
        Jan 16 10:29:23 r-9-VM sshd[1739]: Received disconnect from 169.254.0.1: 11: disconnected by user
        Jan 16 10:29:23 r-9-VM sshd[1739]: pam_unix(sshd:session): session closed for user root
        Jan 16 10:29:52 r-9-VM sshd[1754]: Accepted publickey for root from 169.254.0.1 port 59850 ssh2
        Jan 16 10:29:52 r-9-VM sshd[1754]: pam_unix(sshd:session): session opened for user root by (uid=0)
        Jan 16 10:34:27 r-9-VM sshd[1765]: Accepted publickey for root from 169.254.0.1 port 59852 ssh2
        Jan 16 10:34:27 r-9-VM sshd[1765]: pam_unix(sshd:session): session opened for user root by (uid=0)
        Jan 16 10:34:27 r-9-VM sshd[1765]: Received disconnect from 169.254.0.1: 11: disconnected by user
        Jan 16 10:34:27 r-9-VM sshd[1765]: pam_unix(sshd:session): session closed for user root
        Jan 16 10:35:01 r-9-VM CRON[1769]: pam_unix(cron:session): session opened for user root by (uid=0)

        ---------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------

        VR Logs :
        ============================================================

        1. ifconfig

        eth0 Link encap:Ethernet HWaddr 02:00:0c:43:00:02
        inet addr:10.1.1.1 Bcast:10.1.1.255 Mask:255.255.255.0
        UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
        RX packets:20507 errors:0 dropped:0 overruns:0 frame:0
        TX packets:11563 errors:0 dropped:0 overruns:0 carrier:0
        collisions:0 txqueuelen:1000
        RX bytes:1533963 (1.4 MiB) TX bytes:9939565 (9.4 MiB)

        eth1 Link encap:Ethernet HWaddr 0e:00:a9:fe:03:12
        inet addr:169.254.3.18 Bcast:169.254.255.255 Mask:255.255.0.0
        UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
        RX packets:53809 errors:0 dropped:0 overruns:0 frame:0
        TX packets:42063 errors:0 dropped:0 overruns:0 carrier:0
        collisions:0 txqueuelen:1000
        RX bytes:8224278 (7.8 MiB) TX bytes:7977935 (7.6 MiB)

        eth2 Link encap:Ethernet HWaddr 06:33:c4:00:00:0d
        inet addr:10.102.195.71 Bcast:10.102.195.255 Mask:255.255.252.0
        UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
        RX packets:525762888 errors:0 dropped:0 overruns:0 frame:0
        TX packets:8664 errors:0 dropped:0 overruns:0 carrier:0
        collisions:0 txqueuelen:1000
        RX bytes:499682970 (476.5 MiB) TX bytes:732206 (715.0 KiB)

        lo Link encap:Local Loopback
        inet addr:127.0.0.1 Mask:255.0.0.0
        UP LOOPBACK RUNNING MTU:16436 Metric:1
        RX packets:331 errors:0 dropped:0 overruns:0 frame:0
        TX packets:331 errors:0 dropped:0 overruns:0 carrier:0
        collisions:0 txqueuelen:0
        RX bytes:29179 (28.4 KiB) TX bytes:29179 (28.4 KiB)

        2. Nics

        NIC 1
        Type Isolated
        Traffic Type Guest
        Network Name VM-1
        Netmask 255.255.255.0
        IP Address 10.1.1.1
        ID 4925b18a-1b80-401f-994c-4c1c7f21f4d6
        Network ID ddd99741-549d-4e23-adad-b489df77898d
        Isolation URI vlan://714
        Broadcast URI vlan://714

        NIC 2
        Type
        Traffic Type Control
        Network Name
        Netmask 255.255.0.0
        IP Address 169.254.3.18
        ID b8919075-7479-4d6b-864a-9c68e807f428
        Network ID 7a44608b-60a0-488a-b2db-2187fa346ef0
        Isolation URI
        Broadcast URI

        NIC 3 (Default)
        Type
        Traffic Type Public
        Network Name
        Netmask 255.255.252.0
        IP Address 10.102.195.71
        ID 33c8ec2e-4956-4223-b1e2-1e5fcb795fcc
        Network ID 18d5e28a-ac84-4ed1-87a4-65346f4660f3
        Isolation URI vlan://untagged
        Broadcast URI vlan://untagged

        Here we see that Nic3 i.e eth2 has the public IP and same is there in the cloud.log

        Tue Jan 8 11:32:37 UTC 2013 Executing cloud-early-config
        Tue Jan 8 11:32:37 UTC 2013 Detected that we are running inside kvm guest
        Tue Jan 8 11:32:37 UTC 2013 Patching scripts oldmd5=e1defa60190950fbd3d5e9c15c5b7c28 newmd5=89f718b371578db5f8caa40a1da141f1
        Tue Jan 8 11:32:37 UTC 2013 Patching cloud service
        Tue Jan 8 11:32:38 UTC 2013 Rebooting system since we patched init scripts
        Tue Jan 8 11:32:41 UTC 2013 Setting up virtual router system vm
        Tue Jan 8 11:33:03 UTC 2013 Executing cloud-early-config
        Tue Jan 8 11:33:03 UTC 2013 Detected that we are running inside kvm guest
        Tue Jan 8 11:33:03 UTC 2013 Patching cloud service
        Tue Jan 8 11:33:04 UTC 2013 Setting up virtual router system vm
        Tue Jan 8 11:33:07 UTC 2013 Checking udev NIC assignment order changes
        Tue Jan 8 11:33:07 UTC 2013 Setting up dnsmasq
        Tue Jan 8 11:33:07 UTC 2013 Setting up apache web server
        Tue Jan 8 11:33:07 UTC 2013 Enable service dnsmasq = 1
        Tue Jan 8 11:33:07 UTC 2013 Enable service haproxy = 1
        Tue Jan 8 11:33:07 UTC 2013 Enable service cloud-passwd-srvr = 1
        Tue Jan 8 11:33:07 UTC 2013 Enable service cloud = 0
        Tue Jan 8 11:33:07 UTC 2013 cloud: Tuning rp_filter on public interfaces
        Tue Jan 8 11:33:07 UTC 2013 rpfilter public interfaces : eth2
        Tue Jan 8 11:33:07 UTC 2013 cloud: disable rp_filter on public interfaces
        Tue Jan 8 11:33:07 UTC 2013 cloud: disable rp_filter on public interface: eth2
        Tue Jan 8 11:33:07 UTC 2013 cloud: Enabling rp_filter on Non-public interfaces(eth0,eth1,lo)
        Tue Jan 8 11:33:07 UTC 2013 cloud: enable_fwding = 1
        Tue Jan 8 11:33:07 UTC 2013 enable_fwding = 1

        -------------------------------------------------------------------------------------------------------------------------------------

        Management server logs :
        ============================================================

        1. Management server log

        2013-01-16 16:04:21,867 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-7:null) Access granted to Acct[2-admin] to Domain:1/ by DomainChecker
        2013-01-16 16:04:26,822 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-6:null) Ping from 3
        2013-01-16 16:04:29,777 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-8:null) Ping from 4
        2013-01-16 16:04:30,975 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-2:null) Ping from 1
        2013-01-16 16:04:33,776 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-2:null) submit async job-13, details: AsyncJobVO {id:13, userId: 2, accountId: 2, sessionKey: null, instanceType: None, instanceId: 2, cmd: com.cloud.api.commands.CreateVpnConnectionCmd, cmdOriginator: null, cmdInfo:

        {"id":"2","response":"json","sessionkey":"GDFeOLnqYO9IrSat5FlkpyhAxS8\u003d","s2scustomergatewayid":"5ea05ac3-eba6-475a-a7a7-e272117d7ded","ctxUserId":"2","s2svpngatewayid":"568f2fab-171d-4a58-8af3-7c75fa84e078","_":"1358332456155","ctxAccountId":"2","ctxStartEventId":"103"}

        , cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 129936880108802, completeMsid: null, lastUpdated: null, lastPolled: null, created: null}
        2013-01-16 16:04:33,780 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-13) Executing com.cloud.api.commands.CreateVpnConnectionCmd for job-13
        2013-01-16 16:04:33,785 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-13) Sync job-13 execution on object vpc.2
        2013-01-16 16:04:33,789 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-13) job com.cloud.api.commands.CreateVpnConnectionCmd for job-13 was queued, processing the queue.
        2013-01-16 16:04:33,793 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-13) Executing sync queue item: SyncQueueItemVO

        {id:5, queueId: 5, contentType: AsyncJob, contentId: 13, lastProcessMsid: 129936880108802, lastprocessNumber: 2, created: Wed Jan 16 16:04:33 IST 2013}

        2013-01-16 16:04:33,794 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-13) Schedule queued job-13
        2013-01-16 16:04:33,798 DEBUG [cloud.async.SyncQueueManagerImpl] (Job-Executor-17:job-13) There is a pending process in sync queue(id: 5)
        2013-01-16 16:04:33,800 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-18:job-13) Executing com.cloud.api.commands.CreateVpnConnectionCmd for job-13
        2013-01-16 16:04:33,829 DEBUG [agent.transport.Request] (Job-Executor-18:job-13) Seq 1-1026775662: Sending { Cmd , MgmtId: 129936880108802, via: 1, Ver: v1, Flags: 100101, [{"routing.Site2SiteVpnCfgCommand":{"create":true,"localPublicIp":"10.102.195.74","localGuestCidr":"10.1.1.1/16","localPublicGateway":"10.102.192.1","peerGatewayIp":"217.70.20.213","peerGuestCidrList":"192.168.10.0/24","ipsecPsk":"blablablablablabla","ikePolicy":"3des-md5","espPolicy":"3des-md5","ikeLifetime":86400,"espLifetime":3600,"dpd":false,"accessDetails":

        {"zone.network.type":"Advanced","router.ip":"169.254.0.4","router.name":"r-9-VM"}

        ,"wait":0}}] }
        2013-01-16 16:04:33,988 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 1-1026775662: Processing: { Ans: , MgmtId: 129936880108802, via: 1, Ver: v1, Flags: 100, [{"Answer":{"result":false,"details":"Configure site to site VPN failed due to bash: /opt/cloud/bin/ipsectunnel: No such file or directory","wait":0}}] }
        2013-01-16 16:04:33,988 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-9:null) Seq 1-1026775662: No more commands found
        2013-01-16 16:04:33,988 DEBUG [agent.transport.Request] (Job-Executor-18:job-13) Seq 1-1026775662: Received: { Ans: , MgmtId: 129936880108802, via: 1, Ver: v1, Flags: 100,

        { Answer }

        }
        2013-01-16 16:04:33,992 WARN [api.commands.CreateVpnConnectionCmd] (Job-Executor-18:job-13) Exception:
        com.cloud.exception.ResourceUnavailableException: Resource [Site2SiteVpnConnection:2] is unreachable: Failed to apply site-to-site VPN
        at com.cloud.network.vpn.Site2SiteVpnManagerImpl.startVpnConnection(Site2SiteVpnManagerImpl.java:343)
        at com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
        at com.cloud.api.commands.CreateVpnConnectionCmd.execute(CreateVpnConnectionCmd.java:119)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138)
        at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:432)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
        2013-01-16 16:04:33,999 WARN [cloud.api.ApiDispatcher] (Job-Executor-18:job-13) class com.cloud.api.ServerApiException : Resource [Site2SiteVpnConnection:2] is unreachable: Failed to apply site-to-site VPN
        2013-01-16 16:04:33,999 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-18:job-13) Complete async job-13, jobStatus: 2, resultCode: 530, result: Error Code: 534 Error text: Resource [Site2SiteVpnConnection:2] is unreachable: Failed to apply site-to-site VPN
        2013-01-16 16:04:34,021 DEBUG [cloud.async.SyncQueueManagerImpl] (Job-Executor-18:job-13) Sync queue (5) is currently empty
        2013-01-16 16:04:35,944 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
        2013-01-16 16:04:36,089 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy
        2013-01-16 16:04:36,679 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 1 routers.
        2013-01-16 16:04:38,797 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-22:null) Async job-13 completed
        2013-01-16 16:04:49,740 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) StorageCollector is running...
        2013-01-16 16:04:49,794 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 3-578493520: Received: { Ans: , MgmtId: 129936880108802, via: 3, Ver: v1, Flags: 10,

        { GetStorageStatsAnswer } }
        2013-01-16 16:04:49,881 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 1-1026775663: Received: { Ans: , MgmtId: 129936880108802, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer }

        }
        2013-01-16 16:05:04,596 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) HostStatsCollector is running...
        2013-01-16 16:05:05,188 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 1-1026775664: Received: { Ans: , MgmtId: 129936880108802, via: 1, Ver: v1, Flags: 10,

        { GetHostStatsAnswer }

        }
        2013-01-16 16:05:05,944 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM
        2013-01-16 16:05:06,090 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy

        2. Catalina logs

        WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1 unable to find stats for account: 2
        WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1 unable to find stats for account: 2
        INFO [cloud.ha.HighAvailabilityManagerImpl] (HA-4 checking health of usage server
        WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1 unable to find stats for account: 2
        WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1 unable to find stats for account: 2
        INFO [cloud.ha.HighAvailabilityManagerImpl] (HA-1 checking health of usage server
        WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1 unable to find stats for account: 2
        WARN [network.element.VpcVirtualRouterElement] (Job-Executor-14:job-11) Network Ntwk[200|Public|1] is not associated with any VPC
        WARN [network.element.VpcVirtualRouterElement] (Job-Executor-14:job-11) Network Ntwk[202|Control|3] is not associated with any VPC
        WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1 unable to find stats for account: 2
        WARN [api.commands.CreateVpnConnectionCmd] (Job-Executor-18:job-13) Exception:
        com.cloud.exception.ResourceUnavailableException: Resource [Site2SiteVpnConnection:2] is unreachable: Failed to apply site-to-site VPN
        at com.cloud.network.vpn.Site2SiteVpnManagerImpl.startVpnConnection(Site2SiteVpnManagerImpl.java:343)
        at com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34)
        at com.cloud.api.commands.CreateVpnConnectionCmd.execute(CreateVpnConnectionCmd.java:119)
        at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138)
        at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:432)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
        at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334)
        at java.util.concurrent.FutureTask.run(FutureTask.java:166)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603)
        at java.lang.Thread.run(Thread.java:679)
        WARN [cloud.api.ApiDispatcher] (Job-Executor-18:job-13) class com.cloud.api.ServerApiException : Resource [Site2SiteVpnConnection:2] is unreachable: Failed to apply site-to-site VPN

        Show
        Abhinav Roy added a comment - Hi Sheng, I tested this feature in my environment but with the same customer VPN gateway details as used by Richard and here are my findings :- VPC VR logs :- ========================================================== 1. root@r-9-VM:/var/log# ifconfig eth0 Link encap:Ethernet HWaddr 0e:00:a9:fe:00:04 inet addr:169.254.0.4 Bcast:169.254.255.255 Mask:255.255.0.0 UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:1023 errors:0 dropped:0 overruns:0 frame:0 TX packets:668 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:105813 (103.3 KiB) TX bytes:175004 (170.9 KiB) eth1 Link encap:Ethernet HWaddr 06:3c:62:00:00:10 inet addr:10.102.195.74 Bcast:10.102.195.255 Mask:255.255.252.0 UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:53518 errors:0 dropped:0 overruns:0 frame:0 TX packets:2 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:3766292 (3.5 MiB) TX bytes:84 (84.0 B) lo Link encap:Local Loopback inet addr:127.0.0.1 Mask:255.0.0.0 UP LOOPBACK RUNNING MTU:16436 Metric:1 RX packets:6 errors:0 dropped:0 overruns:0 frame:0 TX packets:6 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:0 RX bytes:414 (414.0 B) TX bytes:414 (414.0 B) 2. Nics. NIC 1 Type Traffic Type Control Network Name Netmask 255.255.0.0 IP Address 169.254.0.4 ID a1b03f69-3606-486e-a7d6-504878bf6184 Network ID 7a44608b-60a0-488a-b2db-2187fa346ef0 Isolation URI Broadcast URI NIC 2 (Default) Type Traffic Type Public Network Name Netmask 255.255.252.0 IP Address 10.102.195.74 ID b3d3de74-1f6a-4f81-9f27-7d23682ca948 Network ID 18d5e28a-ac84-4ed1-87a4-65346f4660f3 Isolation URI vlan://untagged Broadcast URI vlan://untagged Here we see that the NIC-2 which is Eth1 has the public IP. But lets see in the cloud.log, here Eth1 is not treated as the public interface Jan 16 10:29:11 r-9-VM sshd [1427] : Server listening on 169.254.0.4 port 3922. Jan 16 10:29:11 r-9-VM sshd [1427] : error: Bind to port 3922 on 169.254.0.4 failed: Address already in use. Jan 16 10:29:20 r-9-VM sshd [1612] : Did not receive identification string from 169.254.0.1 Jan 16 10:29:20 r-9-VM sshd [1613] : Accepted publickey for root from 169.254.0.1 port 59845 ssh2 Wed Jan 16 10:28:51 UTC 2013 Executing cloud-early-config Wed Jan 16 10:28:51 UTC 2013 Detected that we are running inside kvm guest Wed Jan 16 10:28:51 UTC 2013 Patching scripts oldmd5=e1defa60190950fbd3d5e9c15c5b7c28 newmd5=89f718b371578db5f8caa40a1da141f1 Wed Jan 16 10:28:51 UTC 2013 Patching cloud service Wed Jan 16 10:28:53 UTC 2013 Rebooting system since we patched init scripts Wed Jan 16 10:29:09 UTC 2013 Executing cloud-early-config Wed Jan 16 10:29:09 UTC 2013 Detected that we are running inside kvm guest Wed Jan 16 10:29:09 UTC 2013 Patching cloud service Wed Jan 16 10:29:11 UTC 2013 Setting up VPC virtual router system vm Wed Jan 16 10:29:11 UTC 2013 Setting up apache web server for VPC Wed Jan 16 10:29:11 UTC 2013 Enable service dnsmasq = 1 Wed Jan 16 10:29:11 UTC 2013 Enable service haproxy = 1 Wed Jan 16 10:29:11 UTC 2013 Enable service cloud = 0 Wed Jan 16 10:29:11 UTC 2013 cloud: Tuning rp_filter on public interfaces Wed Jan 16 10:29:11 UTC 2013 rpfilter public interfaces : Wed Jan 16 10:29:11 UTC 2013 cloud: disable rp_filter on public interfaces Wed Jan 16 10:29:11 UTC 2013 cloud: Enabling rp_filter on Non-public interfaces(eth0,eth1,lo) ----------------------------------->>>> Here we see that it treats eth1 also as non-public interface Wed Jan 16 10:29:11 UTC 2013 cloud: enable_fwding = 1 Wed Jan 16 10:29:11 UTC 2013 enable_fwding = 1 4. Auth.log Jan 16 10:29:11 r-9-VM sshd [1427] : Server listening on 169.254.0.4 port 3922. Jan 16 10:29:11 r-9-VM sshd [1427] : error: Bind to port 3922 on 169.254.0.4 failed: Address already in use. Jan 16 10:29:20 r-9-VM sshd [1612] : Did not receive identification string from 169.254.0.1 Jan 16 10:29:20 r-9-VM sshd [1613] : Accepted publickey for root from 169.254.0.1 port 59845 ssh2 Jan 16 10:29:20 r-9-VM sshd [1613] : pam_unix(sshd:session): session opened for user root by (uid=0) Jan 16 10:29:20 r-9-VM sshd [1613] : Received disconnect from 169.254.0.1: 11: disconnected by user Jan 16 10:29:20 r-9-VM sshd [1613] : pam_unix(sshd:session): session closed for user root Jan 16 10:29:20 r-9-VM sshd [1618] : Accepted publickey for root from 169.254.0.1 port 59846 ssh2 Jan 16 10:29:20 r-9-VM sshd [1618] : pam_unix(sshd:session): session opened for user root by (uid=0) Jan 16 10:29:20 r-9-VM sshd [1618] : Received disconnect from 169.254.0.1: 11: disconnected by user Jan 16 10:29:20 r-9-VM sshd [1618] : pam_unix(sshd:session): session closed for user root Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/bin/echo 1 Table_eth1 Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip rule add fwmark 1 table Table_eth1 Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush table Table_eth1 Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush cache Jan 16 10:29:20 r-9-VM sshd [1648] : Accepted publickey for root from 169.254.0.1 port 59847 ssh2 Jan 16 10:29:20 r-9-VM sshd [1648] : pam_unix(sshd:session): session opened for user root by (uid=0) Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip link show eth1 Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip addr add dev eth1 10.102.195.74/22 brd + Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip link set eth1 up Jan 16 10:29:20 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/usr/bin/arping -c 3 -I eth1 -A -U -s 10.102.195.74 10.102.195.74 Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables-save -t mangle Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t mangle -A PREROUTING -i eth1 -m state --state NEW -j CONNMARK --set-mark 1 Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add 10.102.192.0/22 dev eth1 table Table_eth1 proto static Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add default via 10.102.192.1 table Table_eth1 proto static Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route flush cache Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route Jan 16 10:29:22 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip route add default via 10.102.192.1 Jan 16 10:29:22 r-9-VM sshd [1648] : Received disconnect from 169.254.0.1: 11: disconnected by user Jan 16 10:29:22 r-9-VM sshd [1648] : pam_unix(sshd:session): session closed for user root Jan 16 10:29:23 r-9-VM sshd [1708] : Accepted publickey for root from 169.254.0.1 port 59848 ssh2 Jan 16 10:29:23 r-9-VM sshd [1708] : pam_unix(sshd:session): session opened for user root by (uid=0) Jan 16 10:29:23 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -D FORWARD -s 10.1.1.1/16 ! -d 10.1.1.1/16 -j ACCEPT Jan 16 10:29:23 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -A FORWARD -s 10.1.1.1/16 ! -d 10.1.1.1/16 -j ACCEPT Jan 16 10:29:23 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t nat -D POSTROUTING -j SNAT -o eth1 --to-source 10.102.195.74 Jan 16 10:29:23 r-9-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/iptables -t nat -A POSTROUTING -j SNAT -o eth1 --to-source 10.102.195.74 Jan 16 10:29:23 r-9-VM sshd [1708] : Received disconnect from 169.254.0.1: 11: disconnected by user Jan 16 10:29:23 r-9-VM sshd [1708] : pam_unix(sshd:session): session closed for user root Jan 16 10:29:23 r-9-VM sshd [1739] : Accepted publickey for root from 169.254.0.1 port 59849 ssh2 Jan 16 10:29:23 r-9-VM sshd [1739] : pam_unix(sshd:session): session opened for user root by (uid=0) Jan 16 10:29:23 r-9-VM sshd [1739] : Received disconnect from 169.254.0.1: 11: disconnected by user Jan 16 10:29:23 r-9-VM sshd [1739] : pam_unix(sshd:session): session closed for user root Jan 16 10:29:52 r-9-VM sshd [1754] : Accepted publickey for root from 169.254.0.1 port 59850 ssh2 Jan 16 10:29:52 r-9-VM sshd [1754] : pam_unix(sshd:session): session opened for user root by (uid=0) Jan 16 10:34:27 r-9-VM sshd [1765] : Accepted publickey for root from 169.254.0.1 port 59852 ssh2 Jan 16 10:34:27 r-9-VM sshd [1765] : pam_unix(sshd:session): session opened for user root by (uid=0) Jan 16 10:34:27 r-9-VM sshd [1765] : Received disconnect from 169.254.0.1: 11: disconnected by user Jan 16 10:34:27 r-9-VM sshd [1765] : pam_unix(sshd:session): session closed for user root Jan 16 10:35:01 r-9-VM CRON [1769] : pam_unix(cron:session): session opened for user root by (uid=0) --------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------------- VR Logs : ============================================================ 1. ifconfig eth0 Link encap:Ethernet HWaddr 02:00:0c:43:00:02 inet addr:10.1.1.1 Bcast:10.1.1.255 Mask:255.255.255.0 UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:20507 errors:0 dropped:0 overruns:0 frame:0 TX packets:11563 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:1533963 (1.4 MiB) TX bytes:9939565 (9.4 MiB) eth1 Link encap:Ethernet HWaddr 0e:00:a9:fe:03:12 inet addr:169.254.3.18 Bcast:169.254.255.255 Mask:255.255.0.0 UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:53809 errors:0 dropped:0 overruns:0 frame:0 TX packets:42063 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:8224278 (7.8 MiB) TX bytes:7977935 (7.6 MiB) eth2 Link encap:Ethernet HWaddr 06:33:c4:00:00:0d inet addr:10.102.195.71 Bcast:10.102.195.255 Mask:255.255.252.0 UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1 RX packets:525762888 errors:0 dropped:0 overruns:0 frame:0 TX packets:8664 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:1000 RX bytes:499682970 (476.5 MiB) TX bytes:732206 (715.0 KiB) lo Link encap:Local Loopback inet addr:127.0.0.1 Mask:255.0.0.0 UP LOOPBACK RUNNING MTU:16436 Metric:1 RX packets:331 errors:0 dropped:0 overruns:0 frame:0 TX packets:331 errors:0 dropped:0 overruns:0 carrier:0 collisions:0 txqueuelen:0 RX bytes:29179 (28.4 KiB) TX bytes:29179 (28.4 KiB) 2. Nics NIC 1 Type Isolated Traffic Type Guest Network Name VM-1 Netmask 255.255.255.0 IP Address 10.1.1.1 ID 4925b18a-1b80-401f-994c-4c1c7f21f4d6 Network ID ddd99741-549d-4e23-adad-b489df77898d Isolation URI vlan://714 Broadcast URI vlan://714 NIC 2 Type Traffic Type Control Network Name Netmask 255.255.0.0 IP Address 169.254.3.18 ID b8919075-7479-4d6b-864a-9c68e807f428 Network ID 7a44608b-60a0-488a-b2db-2187fa346ef0 Isolation URI Broadcast URI NIC 3 (Default) Type Traffic Type Public Network Name Netmask 255.255.252.0 IP Address 10.102.195.71 ID 33c8ec2e-4956-4223-b1e2-1e5fcb795fcc Network ID 18d5e28a-ac84-4ed1-87a4-65346f4660f3 Isolation URI vlan://untagged Broadcast URI vlan://untagged Here we see that Nic3 i.e eth2 has the public IP and same is there in the cloud.log Tue Jan 8 11:32:37 UTC 2013 Executing cloud-early-config Tue Jan 8 11:32:37 UTC 2013 Detected that we are running inside kvm guest Tue Jan 8 11:32:37 UTC 2013 Patching scripts oldmd5=e1defa60190950fbd3d5e9c15c5b7c28 newmd5=89f718b371578db5f8caa40a1da141f1 Tue Jan 8 11:32:37 UTC 2013 Patching cloud service Tue Jan 8 11:32:38 UTC 2013 Rebooting system since we patched init scripts Tue Jan 8 11:32:41 UTC 2013 Setting up virtual router system vm Tue Jan 8 11:33:03 UTC 2013 Executing cloud-early-config Tue Jan 8 11:33:03 UTC 2013 Detected that we are running inside kvm guest Tue Jan 8 11:33:03 UTC 2013 Patching cloud service Tue Jan 8 11:33:04 UTC 2013 Setting up virtual router system vm Tue Jan 8 11:33:07 UTC 2013 Checking udev NIC assignment order changes Tue Jan 8 11:33:07 UTC 2013 Setting up dnsmasq Tue Jan 8 11:33:07 UTC 2013 Setting up apache web server Tue Jan 8 11:33:07 UTC 2013 Enable service dnsmasq = 1 Tue Jan 8 11:33:07 UTC 2013 Enable service haproxy = 1 Tue Jan 8 11:33:07 UTC 2013 Enable service cloud-passwd-srvr = 1 Tue Jan 8 11:33:07 UTC 2013 Enable service cloud = 0 Tue Jan 8 11:33:07 UTC 2013 cloud: Tuning rp_filter on public interfaces Tue Jan 8 11:33:07 UTC 2013 rpfilter public interfaces : eth2 Tue Jan 8 11:33:07 UTC 2013 cloud: disable rp_filter on public interfaces Tue Jan 8 11:33:07 UTC 2013 cloud: disable rp_filter on public interface: eth2 Tue Jan 8 11:33:07 UTC 2013 cloud: Enabling rp_filter on Non-public interfaces(eth0,eth1,lo) Tue Jan 8 11:33:07 UTC 2013 cloud: enable_fwding = 1 Tue Jan 8 11:33:07 UTC 2013 enable_fwding = 1 ------------------------------------------------------------------------------------------------------------------------------------- Management server logs : ============================================================ 1. Management server log 2013-01-16 16:04:21,867 DEBUG [cloud.user.AccountManagerImpl] (catalina-exec-7:null) Access granted to Acct [2-admin] to Domain:1/ by DomainChecker 2013-01-16 16:04:26,822 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-6:null) Ping from 3 2013-01-16 16:04:29,777 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-8:null) Ping from 4 2013-01-16 16:04:30,975 DEBUG [agent.manager.AgentManagerImpl] (AgentManager-Handler-2:null) Ping from 1 2013-01-16 16:04:33,776 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-2:null) submit async job-13, details: AsyncJobVO {id:13, userId: 2, accountId: 2, sessionKey: null, instanceType: None, instanceId: 2, cmd: com.cloud.api.commands.CreateVpnConnectionCmd, cmdOriginator: null, cmdInfo: {"id":"2","response":"json","sessionkey":"GDFeOLnqYO9IrSat5FlkpyhAxS8\u003d","s2scustomergatewayid":"5ea05ac3-eba6-475a-a7a7-e272117d7ded","ctxUserId":"2","s2svpngatewayid":"568f2fab-171d-4a58-8af3-7c75fa84e078","_":"1358332456155","ctxAccountId":"2","ctxStartEventId":"103"} , cmdVersion: 0, callbackType: 0, callbackAddress: null, status: 0, processStatus: 0, resultCode: 0, result: null, initMsid: 129936880108802, completeMsid: null, lastUpdated: null, lastPolled: null, created: null} 2013-01-16 16:04:33,780 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-13) Executing com.cloud.api.commands.CreateVpnConnectionCmd for job-13 2013-01-16 16:04:33,785 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-13) Sync job-13 execution on object vpc.2 2013-01-16 16:04:33,789 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-13) job com.cloud.api.commands.CreateVpnConnectionCmd for job-13 was queued, processing the queue. 2013-01-16 16:04:33,793 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-13) Executing sync queue item: SyncQueueItemVO {id:5, queueId: 5, contentType: AsyncJob, contentId: 13, lastProcessMsid: 129936880108802, lastprocessNumber: 2, created: Wed Jan 16 16:04:33 IST 2013} 2013-01-16 16:04:33,794 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-17:job-13) Schedule queued job-13 2013-01-16 16:04:33,798 DEBUG [cloud.async.SyncQueueManagerImpl] (Job-Executor-17:job-13) There is a pending process in sync queue(id: 5) 2013-01-16 16:04:33,800 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-18:job-13) Executing com.cloud.api.commands.CreateVpnConnectionCmd for job-13 2013-01-16 16:04:33,829 DEBUG [agent.transport.Request] (Job-Executor-18:job-13) Seq 1-1026775662: Sending { Cmd , MgmtId: 129936880108802, via: 1, Ver: v1, Flags: 100101, [{"routing.Site2SiteVpnCfgCommand":{"create":true,"localPublicIp":"10.102.195.74","localGuestCidr":"10.1.1.1/16","localPublicGateway":"10.102.192.1","peerGatewayIp":"217.70.20.213","peerGuestCidrList":"192.168.10.0/24","ipsecPsk":"blablablablablabla","ikePolicy":"3des-md5","espPolicy":"3des-md5","ikeLifetime":86400,"espLifetime":3600,"dpd":false,"accessDetails": {"zone.network.type":"Advanced","router.ip":"169.254.0.4","router.name":"r-9-VM"} ,"wait":0}}] } 2013-01-16 16:04:33,988 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 1-1026775662: Processing: { Ans: , MgmtId: 129936880108802, via: 1, Ver: v1, Flags: 100, [{"Answer":{"result":false,"details":"Configure site to site VPN failed due to bash: /opt/cloud/bin/ipsectunnel: No such file or directory","wait":0}}] } 2013-01-16 16:04:33,988 DEBUG [agent.manager.AgentAttache] (AgentManager-Handler-9:null) Seq 1-1026775662: No more commands found 2013-01-16 16:04:33,988 DEBUG [agent.transport.Request] (Job-Executor-18:job-13) Seq 1-1026775662: Received: { Ans: , MgmtId: 129936880108802, via: 1, Ver: v1, Flags: 100, { Answer } } 2013-01-16 16:04:33,992 WARN [api.commands.CreateVpnConnectionCmd] (Job-Executor-18:job-13) Exception: com.cloud.exception.ResourceUnavailableException: Resource [Site2SiteVpnConnection:2] is unreachable: Failed to apply site-to-site VPN at com.cloud.network.vpn.Site2SiteVpnManagerImpl.startVpnConnection(Site2SiteVpnManagerImpl.java:343) at com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34) at com.cloud.api.commands.CreateVpnConnectionCmd.execute(CreateVpnConnectionCmd.java:119) at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138) at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:432) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:679) 2013-01-16 16:04:33,999 WARN [cloud.api.ApiDispatcher] (Job-Executor-18:job-13) class com.cloud.api.ServerApiException : Resource [Site2SiteVpnConnection:2] is unreachable: Failed to apply site-to-site VPN 2013-01-16 16:04:33,999 DEBUG [cloud.async.AsyncJobManagerImpl] (Job-Executor-18:job-13) Complete async job-13, jobStatus: 2, resultCode: 530, result: Error Code: 534 Error text: Resource [Site2SiteVpnConnection:2] is unreachable: Failed to apply site-to-site VPN 2013-01-16 16:04:34,021 DEBUG [cloud.async.SyncQueueManagerImpl] (Job-Executor-18:job-13) Sync queue (5) is currently empty 2013-01-16 16:04:35,944 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM 2013-01-16 16:04:36,089 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy 2013-01-16 16:04:36,679 DEBUG [network.router.VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 1 routers. 2013-01-16 16:04:38,797 DEBUG [cloud.async.AsyncJobManagerImpl] (catalina-exec-22:null) Async job-13 completed 2013-01-16 16:04:49,740 DEBUG [cloud.server.StatsCollector] (StatsCollector-3:null) StorageCollector is running... 2013-01-16 16:04:49,794 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 3-578493520: Received: { Ans: , MgmtId: 129936880108802, via: 3, Ver: v1, Flags: 10, { GetStorageStatsAnswer } } 2013-01-16 16:04:49,881 DEBUG [agent.transport.Request] (StatsCollector-3:null) Seq 1-1026775663: Received: { Ans: , MgmtId: 129936880108802, via: 1, Ver: v1, Flags: 10, { GetStorageStatsAnswer } } 2013-01-16 16:05:04,596 DEBUG [cloud.server.StatsCollector] (StatsCollector-2:null) HostStatsCollector is running... 2013-01-16 16:05:05,188 DEBUG [agent.transport.Request] (StatsCollector-2:null) Seq 1-1026775664: Received: { Ans: , MgmtId: 129936880108802, via: 1, Ver: v1, Flags: 10, { GetHostStatsAnswer } } 2013-01-16 16:05:05,944 DEBUG [storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1 is ready to launch secondary storage VM 2013-01-16 16:05:06,090 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl] (consoleproxy-1:null) Zone 1 is ready to launch console proxy 2. Catalina logs WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1 unable to find stats for account: 2 WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1 unable to find stats for account: 2 INFO [cloud.ha.HighAvailabilityManagerImpl] (HA-4 checking health of usage server WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1 unable to find stats for account: 2 WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1 unable to find stats for account: 2 INFO [cloud.ha.HighAvailabilityManagerImpl] (HA-1 checking health of usage server WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1 unable to find stats for account: 2 WARN [network.element.VpcVirtualRouterElement] (Job-Executor-14:job-11) Network Ntwk [200|Public|1] is not associated with any VPC WARN [network.element.VpcVirtualRouterElement] (Job-Executor-14:job-11) Network Ntwk [202|Control|3] is not associated with any VPC WARN [network.router.VirtualNetworkApplianceManagerImpl] (RouterMonitor-1 unable to find stats for account: 2 WARN [api.commands.CreateVpnConnectionCmd] (Job-Executor-18:job-13) Exception: com.cloud.exception.ResourceUnavailableException: Resource [Site2SiteVpnConnection:2] is unreachable: Failed to apply site-to-site VPN at com.cloud.network.vpn.Site2SiteVpnManagerImpl.startVpnConnection(Site2SiteVpnManagerImpl.java:343) at com.cloud.utils.db.DatabaseCallback.intercept(DatabaseCallback.java:34) at com.cloud.api.commands.CreateVpnConnectionCmd.execute(CreateVpnConnectionCmd.java:119) at com.cloud.api.ApiDispatcher.dispatch(ApiDispatcher.java:138) at com.cloud.async.AsyncJobManagerImpl$1.run(AsyncJobManagerImpl.java:432) at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471) at java.util.concurrent.FutureTask$Sync.innerRun(FutureTask.java:334) at java.util.concurrent.FutureTask.run(FutureTask.java:166) at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1110) at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:603) at java.lang.Thread.run(Thread.java:679) WARN [cloud.api.ApiDispatcher] (Job-Executor-18:job-13) class com.cloud.api.ServerApiException : Resource [Site2SiteVpnConnection:2] is unreachable: Failed to apply site-to-site VPN
        Hide
        Marcus Sorensen added a comment -

        I can verify that in my setup as well in cloud.log (the rp_filter issue), I'll take a look and see what's going on there. However, the VPC router is functional, as the rp_filter isn't strictly required. Your setup looks like it got the interfaces set up properly, as opposed to the previous logs where one interface is down. Despite that, it looks like the VPN failed in your setup, I'll see if I can get that working.

        Show
        Marcus Sorensen added a comment - I can verify that in my setup as well in cloud.log (the rp_filter issue), I'll take a look and see what's going on there. However, the VPC router is functional, as the rp_filter isn't strictly required. Your setup looks like it got the interfaces set up properly, as opposed to the previous logs where one interface is down. Despite that, it looks like the VPN failed in your setup, I'll see if I can get that working.
        Hide
        Joe Brockmeier added a comment -

        This is not a blocker bug, I'm moving this to 4.0.2 so we can get 4.0.1 out the door before February.

        Show
        Joe Brockmeier added a comment - This is not a blocker bug, I'm moving this to 4.0.2 so we can get 4.0.1 out the door before February.
        Hide
        Sheng Yang added a comment - - edited

        2013-01-16 16:04:33,988 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 1-1026775662: Processing: { Ans: , MgmtId: 129936880108802, via: 1, Ver: v1, Flags: 100, [{"Answer":{"result":false,"details":"Configure site to site VPN failed due to bash: /opt/cloud/bin/ipsectunnel: No such file or directory","wait":0}}] }"

        File is not in KVM agent's package, or ISO?

        Though I don't quite understand how KVM agent works here...

        Show
        Sheng Yang added a comment - - edited 2013-01-16 16:04:33,988 DEBUG [agent.transport.Request] (AgentManager-Handler-9:null) Seq 1-1026775662: Processing: { Ans: , MgmtId: 129936880108802, via: 1, Ver: v1, Flags: 100, [{"Answer":{"result":false,"details":"Configure site to site VPN failed due to bash: /opt/cloud/bin/ipsectunnel: No such file or directory","wait":0}}] }" File is not in KVM agent's package, or ISO? Though I don't quite understand how KVM agent works here...
        Hide
        Marcus Sorensen added a comment -

        /opt/cloud/bin/ipsectunnel.sh exists, but not /opt/cloud/bin/ipsectunnel. I checked both an environment running master and one running 4.0.1. I'll fix this to ipsectunnel.sh and then I'll try to get a vpn test going. I'm not sure if this will fix the ethnull issue, or if that's fallout from this or what.

        Show
        Marcus Sorensen added a comment - /opt/cloud/bin/ipsectunnel.sh exists, but not /opt/cloud/bin/ipsectunnel. I checked both an environment running master and one running 4.0.1. I'll fix this to ipsectunnel.sh and then I'll try to get a vpn test going. I'm not sure if this will fix the ethnull issue, or if that's fallout from this or what.
        Hide
        Marcus Sorensen added a comment -

        fix is in master

        Show
        Marcus Sorensen added a comment - fix is in master
        Hide
        Sheng Yang added a comment -

        Oops, likely a typo...

        I don't think we can reproduce ethnull issue. Probably we should check with Richard's about the environment and setup again.

        Show
        Sheng Yang added a comment - Oops, likely a typo... I don't think we can reproduce ethnull issue. Probably we should check with Richard's about the environment and setup again.
        Hide
        Marcus Sorensen added a comment - - edited

        Someone could try pulling commit b77503b5bd001d1038bb4cd79c04db7ca993e94e into a local 4.0 branch and testing if they've already got an environment set up to do so. I'll try to figure one out in the mean time but I may not get to it right away. That commit only changes ipsectunnel to ipsectunnel.sh.

        As far as the rp_filter, it looks a bit hairy. The script that sets up the rp_filter is simple, it just says that anything that is not eth0 or eth1 is a public interface, which is flawed, but works for the standard VR. The reason why it looks like it does in Abihnav's test is that the VPC router only starts with eth0 and eth1, then adds a nic for each isolated network afterward, so no nic is marked public, because there is no interface on boot that is not an eth0 or eth1. The regular isolated router, however, starts up with eth0,1,and 2, being isolated, command, and public. The fix I think is to avoid this rp_filter disable code altogether in the VPC router setting rp_filter to off globally, and enable rp_filter when the isolated nics are added via vpc_guestnw.sh

        I don't think the rp_filter issue is causing any immediate problems we have seen thus far, but it does need to be adjusted for VPC routers. This isn't KVM specific. It's in cloud_early_config on the system vm.

        Show
        Marcus Sorensen added a comment - - edited Someone could try pulling commit b77503b5bd001d1038bb4cd79c04db7ca993e94e into a local 4.0 branch and testing if they've already got an environment set up to do so. I'll try to figure one out in the mean time but I may not get to it right away. That commit only changes ipsectunnel to ipsectunnel.sh. As far as the rp_filter, it looks a bit hairy. The script that sets up the rp_filter is simple, it just says that anything that is not eth0 or eth1 is a public interface, which is flawed, but works for the standard VR. The reason why it looks like it does in Abihnav's test is that the VPC router only starts with eth0 and eth1, then adds a nic for each isolated network afterward, so no nic is marked public, because there is no interface on boot that is not an eth0 or eth1. The regular isolated router, however, starts up with eth0,1,and 2, being isolated, command, and public. The fix I think is to avoid this rp_filter disable code altogether in the VPC router setting rp_filter to off globally, and enable rp_filter when the isolated nics are added via vpc_guestnw.sh I don't think the rp_filter issue is causing any immediate problems we have seen thus far, but it does need to be adjusted for VPC routers. This isn't KVM specific. It's in cloud_early_config on the system vm.
        Hide
        Marcus Sorensen added a comment -

        Tested and fixed rp_filter in e37a82375c1dd7631f37de1ed1b336f524d08c62. This enables rp_filter on guest networks as they're added to the VPC, and disables rp_filter for the public, rather than expecting eth2 to be public.

        Show
        Marcus Sorensen added a comment - Tested and fixed rp_filter in e37a82375c1dd7631f37de1ed1b336f524d08c62. This enables rp_filter on guest networks as they're added to the VPC, and disables rp_filter for the public, rather than expecting eth2 to be public.
        Hide
        Richard Shevel added a comment - - edited

        my env:

        2x server for KVM host
        CentOS 6.3 (Kernel-2.6.32-279.14.1.el6.x86_64)
        libvirt-0.9.10-21.el6_3.6.x86_64
        qemu-kvm-0.12.1.2-2.295.el6_3.2.x86_64
        cloud-agent-libs-4.0.1-0.13.el6.4.0.1.x86_64
        cloud-scripts-4.0.1-0.13.el6.4.0.1.x86_64
        cloud-utils-4.0.1-0.13.el6.4.0.1.x86_64
        cloud-deps-4.0.1-0.13.el6.4.0.1.x86_64
        cloud-python-4.0.1-0.13.el6.4.0.1.x86_64
        cloud-core-4.0.1-0.13.el6.4.0.1.x86_64
        cloud-agent-4.0.1-0.13.el6.4.0.1.x86_64

        Network:
        bridge name bridge id STP enabled interfaces
        cloud0 8000.fe00a9fe008f no vnet0
        cloudVirBr50 8000.707be8f0d200 no bond2.50
        cloudbr0 8000.fc48ef2fbd38 no bond1 - private
        cloudbr1 8000.707be8f0d200 no bond2 -public
        cloudbrm 8000.fc48ef2fbd38 no bond1.40 -managment

        BONDING_OPTS="miimon=100 mode=balance-tlb"

        primary storage - CLVM (over iSCSI)

        chkconfig --list
        atop 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        auditd 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        cgconfig 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        cgred 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        cloud-agent 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        clvmd 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        cman 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        corosync 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        dnsmasq 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        ebtables 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        fcoe 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        gfs2 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        haldaemon 0:off 1:off 2:off 3:on 4:on 5:on 6:off
        ip6tables 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        ipmievd 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        iptables 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        iscsi 0:off 1:off 2:on 3:on 4:off 5:off 6:off
        iscsid 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        ksm 0:off 1:off 2:off 3:on 4:on 5:on 6:off
        ksmtuned 0:off 1:off 2:off 3:on 4:on 5:on 6:off
        libvirt-guests 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        libvirtd 0:off 1:off 2:off 3:on 4:on 5:on 6:off
        lldpad 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        lvm2-monitor 0:off 1:on 2:on 3:on 4:on 5:on 6:off
        messagebus 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        modclusterd 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        multipathd 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        netconsole 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        netfs 0:off 1:off 2:off 3:on 4:on 5:on 6:off
        network 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        nfs 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        nfslock 0:off 1:off 2:off 3:on 4:on 5:on 6:off
        ntpd 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        ntpdate 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        numad 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        oddjobd 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        quota_nld 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        radvd 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        rdisc 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        restorecond 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        rgmanager 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        ricci 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        rpcbind 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        rpcgssd 0:off 1:off 2:off 3:on 4:on 5:on 6:off
        rpcidmapd 0:off 1:off 2:off 3:on 4:on 5:on 6:off
        rpcsvcgssd 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        rsyslog 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        saslauthd 0:off 1:off 2:off 3:off 4:off 5:off 6:off
        sshd 0:off 1:off 2:on 3:on 4:on 5:on 6:off
        udev-post 0:off 1:on 2:on 3:on 4:on 5:on 6:off

        VLAN-50 (public)
        VLAN-500-1000 (private)
        VLAN-40 - mgmnt

        1x CS host
        CentOS 6.3 (Kernel-2.6.32-279.14.1.el6.x86_64)
        cloud-aws-api-4.0.1-0.13.el6.4.0.1.x86_64
        cloud-scripts-4.0.1-0.13.el6.4.0.1.x86_64
        cloud-deps-4.0.1-0.13.el6.4.0.1.x86_64
        cloud-server-4.0.1-0.13.el6.4.0.1.x86_64
        cloud-client-ui-4.0.1-0.13.el6.4.0.1.x86_64
        cloud-utils-4.0.1-0.13.el6.4.0.1.x86_64
        cloud-python-4.0.1-0.13.el6.4.0.1.x86_64
        cloud-client-4.0.1-0.13.el6.4.0.1.x86_64
        cloud-core-4.0.1-0.13.el6.4.0.1.x86_64
        cloud-setup-4.0.1-0.13.el6.4.0.1.x86_64
        cloud-usage-4.0.1-0.13.el6.4.0.1.x86_64

        2x DB host
        CentOS 6.3 (Kernel-2.6.32-279.14.1.el6.x86_64)
        Percona-Server-shared-55-5.5.28-rel29.1.335.rhel6.x86_64
        Percona-Server-shared-compat-5.5.28-rel29.1.335.rhel6.x86_64
        Percona-Server-client-55-5.5.28-rel29.1.335.rhel6.x86_64
        Percona-Server-server-55-5.5.28-rel29.1.335.rhel6.x86_64

        replication type: Master-Master

        1x nfs host
        CentOS 6.3 (Kernel-2.6.32-279.14.1.el6.x86_64)
        nfs-utils-1.2.3-26.el6.x86_64

        1x Cluster host (RHCS)
        CentOS 6.3 (Kernel-2.6.32-279.14.1.el6.x86_64)
        cman-3.0.12.1-32.el6_3.2.x86_64

        1x DNS
        CentOS 6.3 (Kernel-2.6.32-279.14.1.el6.x86_64)
        bind-9.8.2-0.10.rc1.el6_3.5.x86_64

        Show
        Richard Shevel added a comment - - edited my env: 2x server for KVM host CentOS 6.3 (Kernel-2.6.32-279.14.1.el6.x86_64) libvirt-0.9.10-21.el6_3.6.x86_64 qemu-kvm-0.12.1.2-2.295.el6_3.2.x86_64 cloud-agent-libs-4.0.1-0.13.el6.4.0.1.x86_64 cloud-scripts-4.0.1-0.13.el6.4.0.1.x86_64 cloud-utils-4.0.1-0.13.el6.4.0.1.x86_64 cloud-deps-4.0.1-0.13.el6.4.0.1.x86_64 cloud-python-4.0.1-0.13.el6.4.0.1.x86_64 cloud-core-4.0.1-0.13.el6.4.0.1.x86_64 cloud-agent-4.0.1-0.13.el6.4.0.1.x86_64 Network: bridge name bridge id STP enabled interfaces cloud0 8000.fe00a9fe008f no vnet0 cloudVirBr50 8000.707be8f0d200 no bond2.50 cloudbr0 8000.fc48ef2fbd38 no bond1 - private cloudbr1 8000.707be8f0d200 no bond2 -public cloudbrm 8000.fc48ef2fbd38 no bond1.40 -managment BONDING_OPTS="miimon=100 mode=balance-tlb" primary storage - CLVM (over iSCSI) chkconfig --list atop 0:off 1:off 2:off 3:off 4:off 5:off 6:off auditd 0:off 1:off 2:on 3:on 4:on 5:on 6:off cgconfig 0:off 1:off 2:on 3:on 4:on 5:on 6:off cgred 0:off 1:off 2:on 3:on 4:on 5:on 6:off cloud-agent 0:off 1:off 2:on 3:on 4:on 5:on 6:off clvmd 0:off 1:off 2:on 3:on 4:on 5:on 6:off cman 0:off 1:off 2:on 3:on 4:on 5:on 6:off corosync 0:off 1:off 2:off 3:off 4:off 5:off 6:off dnsmasq 0:off 1:off 2:off 3:off 4:off 5:off 6:off ebtables 0:off 1:off 2:on 3:on 4:on 5:on 6:off fcoe 0:off 1:off 2:off 3:off 4:off 5:off 6:off gfs2 0:off 1:off 2:off 3:off 4:off 5:off 6:off haldaemon 0:off 1:off 2:off 3:on 4:on 5:on 6:off ip6tables 0:off 1:off 2:off 3:off 4:off 5:off 6:off ipmievd 0:off 1:off 2:off 3:off 4:off 5:off 6:off iptables 0:off 1:off 2:off 3:off 4:off 5:off 6:off iscsi 0:off 1:off 2:on 3:on 4:off 5:off 6:off iscsid 0:off 1:off 2:on 3:on 4:on 5:on 6:off ksm 0:off 1:off 2:off 3:on 4:on 5:on 6:off ksmtuned 0:off 1:off 2:off 3:on 4:on 5:on 6:off libvirt-guests 0:off 1:off 2:on 3:on 4:on 5:on 6:off libvirtd 0:off 1:off 2:off 3:on 4:on 5:on 6:off lldpad 0:off 1:off 2:on 3:on 4:on 5:on 6:off lvm2-monitor 0:off 1:on 2:on 3:on 4:on 5:on 6:off messagebus 0:off 1:off 2:on 3:on 4:on 5:on 6:off modclusterd 0:off 1:off 2:on 3:on 4:on 5:on 6:off multipathd 0:off 1:off 2:on 3:on 4:on 5:on 6:off netconsole 0:off 1:off 2:off 3:off 4:off 5:off 6:off netfs 0:off 1:off 2:off 3:on 4:on 5:on 6:off network 0:off 1:off 2:on 3:on 4:on 5:on 6:off nfs 0:off 1:off 2:on 3:on 4:on 5:on 6:off nfslock 0:off 1:off 2:off 3:on 4:on 5:on 6:off ntpd 0:off 1:off 2:on 3:on 4:on 5:on 6:off ntpdate 0:off 1:off 2:off 3:off 4:off 5:off 6:off numad 0:off 1:off 2:off 3:off 4:off 5:off 6:off oddjobd 0:off 1:off 2:off 3:off 4:off 5:off 6:off quota_nld 0:off 1:off 2:off 3:off 4:off 5:off 6:off radvd 0:off 1:off 2:off 3:off 4:off 5:off 6:off rdisc 0:off 1:off 2:off 3:off 4:off 5:off 6:off restorecond 0:off 1:off 2:off 3:off 4:off 5:off 6:off rgmanager 0:off 1:off 2:on 3:on 4:on 5:on 6:off ricci 0:off 1:off 2:on 3:on 4:on 5:on 6:off rpcbind 0:off 1:off 2:on 3:on 4:on 5:on 6:off rpcgssd 0:off 1:off 2:off 3:on 4:on 5:on 6:off rpcidmapd 0:off 1:off 2:off 3:on 4:on 5:on 6:off rpcsvcgssd 0:off 1:off 2:off 3:off 4:off 5:off 6:off rsyslog 0:off 1:off 2:on 3:on 4:on 5:on 6:off saslauthd 0:off 1:off 2:off 3:off 4:off 5:off 6:off sshd 0:off 1:off 2:on 3:on 4:on 5:on 6:off udev-post 0:off 1:on 2:on 3:on 4:on 5:on 6:off VLAN-50 (public) VLAN-500-1000 (private) VLAN-40 - mgmnt 1x CS host CentOS 6.3 (Kernel-2.6.32-279.14.1.el6.x86_64) cloud-aws-api-4.0.1-0.13.el6.4.0.1.x86_64 cloud-scripts-4.0.1-0.13.el6.4.0.1.x86_64 cloud-deps-4.0.1-0.13.el6.4.0.1.x86_64 cloud-server-4.0.1-0.13.el6.4.0.1.x86_64 cloud-client-ui-4.0.1-0.13.el6.4.0.1.x86_64 cloud-utils-4.0.1-0.13.el6.4.0.1.x86_64 cloud-python-4.0.1-0.13.el6.4.0.1.x86_64 cloud-client-4.0.1-0.13.el6.4.0.1.x86_64 cloud-core-4.0.1-0.13.el6.4.0.1.x86_64 cloud-setup-4.0.1-0.13.el6.4.0.1.x86_64 cloud-usage-4.0.1-0.13.el6.4.0.1.x86_64 2x DB host CentOS 6.3 (Kernel-2.6.32-279.14.1.el6.x86_64) Percona-Server-shared-55-5.5.28-rel29.1.335.rhel6.x86_64 Percona-Server-shared-compat-5.5.28-rel29.1.335.rhel6.x86_64 Percona-Server-client-55-5.5.28-rel29.1.335.rhel6.x86_64 Percona-Server-server-55-5.5.28-rel29.1.335.rhel6.x86_64 replication type: Master-Master 1x nfs host CentOS 6.3 (Kernel-2.6.32-279.14.1.el6.x86_64) nfs-utils-1.2.3-26.el6.x86_64 1x Cluster host (RHCS) CentOS 6.3 (Kernel-2.6.32-279.14.1.el6.x86_64) cman-3.0.12.1-32.el6_3.2.x86_64 1x DNS CentOS 6.3 (Kernel-2.6.32-279.14.1.el6.x86_64) bind-9.8.2-0.10.rc1.el6_3.5.x86_64
        Hide
        Richard Shevel added a comment -

        Marcus, typo in a path (/opt/cloud/bin/ipsectunnel) is also one of the bug (thx for fix), but somewhere else crept error with ethnull. Somewhere on the level of transmission parameters into VR.

        Jan 10 10:28:58 r-292-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush table Table_eth1
        We can see here, eth1 properly transmitted to the VR, but
        Jan 10 10:28:58 r-292-VM sshd[1631]: pam_unix(sshd:session): session opened for user root by (uid=0)
        Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip link show ethnull
        Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip addr add dev ethnull 77.95.133.142/26 brd
        here there was an error with ethnull, had disappeared option eth1

        how to pass a parameter with interface (ethX) to a router ?

        Show
        Richard Shevel added a comment - Marcus, typo in a path (/opt/cloud/bin/ipsectunnel) is also one of the bug (thx for fix), but somewhere else crept error with ethnull. Somewhere on the level of transmission parameters into VR. Jan 10 10:28:58 r-292-VM sudo: root : TTY=unknown ; PWD=/ ; USER=root ; COMMAND=/sbin/ip route flush table Table_eth1 We can see here, eth1 properly transmitted to the VR, but Jan 10 10:28:58 r-292-VM sshd [1631] : pam_unix(sshd:session): session opened for user root by (uid=0) Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip link show ethnull Jan 10 10:28:59 r-292-VM sudo: root : TTY=unknown ; PWD=/root ; USER=root ; COMMAND=/sbin/ip addr add dev ethnull 77.95.133.142/26 brd here there was an error with ethnull, had disappeared option eth1 how to pass a parameter with interface (ethX) to a router ?
        Hide
        Marcus Sorensen added a comment -

        Network:
        bridge name bridge id STP enabled interfaces
        cloud0 8000.fe00a9fe008f no vnet0
        cloudVirBr50 8000.707be8f0d200 no bond2.50
        cloudbr0 8000.fc48ef2fbd38 no bond1 - private
        cloudbr1 8000.707be8f0d200 no bond2 -public
        cloudbrm 8000.fc48ef2fbd38 no bond1.40 -managment

        BONDING_OPTS="miimon=100 mode=balance-tlb"

        primary storage - CLVM (over iSCSI)

        VLAN-50 (public)
        VLAN-500-1000 (private)
        VLAN-40 - mgmnt

        so cloudbr1 is public, and cloudVirBr50 is public?

        If you look at your physical networks in the cloudstack UI (under infrastructure->zones), what is the KVM traffic label for your public traffic? Did you manually create all four of those? The reason I ask is because the cloudVirBr nomenclature was deprecated, so if you didn't create it, that might be a bug right there. Most of my setups don't involve tagged public, I'll give it a whirl and see what I get.

        Show
        Marcus Sorensen added a comment - Network: bridge name bridge id STP enabled interfaces cloud0 8000.fe00a9fe008f no vnet0 cloudVirBr50 8000.707be8f0d200 no bond2.50 cloudbr0 8000.fc48ef2fbd38 no bond1 - private cloudbr1 8000.707be8f0d200 no bond2 -public cloudbrm 8000.fc48ef2fbd38 no bond1.40 -managment BONDING_OPTS="miimon=100 mode=balance-tlb" primary storage - CLVM (over iSCSI) VLAN-50 (public) VLAN-500-1000 (private) VLAN-40 - mgmnt so cloudbr1 is public, and cloudVirBr50 is public? If you look at your physical networks in the cloudstack UI (under infrastructure->zones), what is the KVM traffic label for your public traffic? Did you manually create all four of those? The reason I ask is because the cloudVirBr nomenclature was deprecated, so if you didn't create it, that might be a bug right there. Most of my setups don't involve tagged public, I'll give it a whirl and see what I get.
        Hide
        Richard Shevel added a comment - - edited

        cloudVirBr50 is created automatically (create zone step)
        cloudbr0, cloudbr1 and cloudbrm i created manually.

        In cloudstak UI:
        for public KVM traffic label cloudbr1
        for guest KVM traffic label cloudbr0
        for management KVM traffic label cloudbrm

        Show
        Richard Shevel added a comment - - edited cloudVirBr50 is created automatically (create zone step) cloudbr0, cloudbr1 and cloudbrm i created manually. In cloudstak UI: for public KVM traffic label cloudbr1 for guest KVM traffic label cloudbr0 for management KVM traffic label cloudbrm
        Hide
        Richard Shevel added a comment - - edited

        I attached a screenshot of a public from Cloudstak UI (public.png)

        Show
        Richard Shevel added a comment - - edited I attached a screenshot of a public from Cloudstak UI (public.png)
        Hide
        Marcus Sorensen added a comment -

        I just created a fresh advanced zone with your setup, and it gives me a 'breth1-50' for public instead of the old 'cloudVirBr50'. Was this an upgrade?

        Show
        Marcus Sorensen added a comment - I just created a fresh advanced zone with your setup, and it gives me a 'breth1-50' for public instead of the old 'cloudVirBr50'. Was this an upgrade?
        Hide
        Richard Shevel added a comment -

        No, after upgrade from 4.0.0 to 4.0.1 "brctl show" look like :

        [root@bh4 network-scripts]# brctl show
        bridge name bridge id STP enabled interfaces
        cloud0 8000.fe00a9fe008f no vnet0
        vnet10
        vnet14
        vnet3
        cloudVirBr50 8000.707be8f0d200 no bond2.50
        vnet11
        vnet15
        vnet2
        vnet5
        cloudVirBr504 8000.fc48ef2fbd38 no bond1.504
        cloudVirBr598 8000.fc48ef2fbd38 no bond1.598
        vnet12
        vnet13
        cloudVirBr700 8000.fc48ef2fbd38 no bond1.700
        vnet9
        cloudVirBr813 8000.fc48ef2fbd38 no bond1.813
        cloudVirBr936 8000.fc48ef2fbd38 no bond1.936
        vnet16
        cloudVirBr947 8000.fc48ef2fbd38 no bond1.947
        vnet7
        vnet8
        cloudbr0 8000.fc48ef2fbd38 no bond1
        cloudbr1 8000.707be8f0d200 no bond2
        cloudbrm 8000.fc48ef2fbd38 no bond1.40
        vnet1
        vnet4
        vnet6
        virbr0 8000.525400c8b796 yes virbr0-nic

        Show
        Richard Shevel added a comment - No, after upgrade from 4.0.0 to 4.0.1 "brctl show" look like : [root@bh4 network-scripts] # brctl show bridge name bridge id STP enabled interfaces cloud0 8000.fe00a9fe008f no vnet0 vnet10 vnet14 vnet3 cloudVirBr50 8000.707be8f0d200 no bond2.50 vnet11 vnet15 vnet2 vnet5 cloudVirBr504 8000.fc48ef2fbd38 no bond1.504 cloudVirBr598 8000.fc48ef2fbd38 no bond1.598 vnet12 vnet13 cloudVirBr700 8000.fc48ef2fbd38 no bond1.700 vnet9 cloudVirBr813 8000.fc48ef2fbd38 no bond1.813 cloudVirBr936 8000.fc48ef2fbd38 no bond1.936 vnet16 cloudVirBr947 8000.fc48ef2fbd38 no bond1.947 vnet7 vnet8 cloudbr0 8000.fc48ef2fbd38 no bond1 cloudbr1 8000.707be8f0d200 no bond2 cloudbrm 8000.fc48ef2fbd38 no bond1.40 vnet1 vnet4 vnet6 virbr0 8000.525400c8b796 yes virbr0-nic
        Hide
        Marcus Sorensen added a comment -

        So you started at 4.0...

        The one thing I don't see is your agent log. can you look in the agent log, when the host is freshly started and the agent connects, the first router or vm gets started up you should see something like:

        2013-01-17 14:32:48,891 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) Execution is successful.
        2013-01-17 14:32:48,892 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) Executing: /bin/sh -c brctl show|grep cloud0
        2013-01-17 14:32:48,900 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) Execution is successful.
        2013-01-17 14:32:48,901 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) nic=[Nic:Management-172.17.10.136-null]
        2013-01-17 14:32:48,901 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) nic=[Nic:Public-192.168.100.129-vlan://50]
        2013-01-17 14:32:48,901 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) creating a vlan dev and bridge for public traffic per traffic label cloudbr1
        2013-01-17 14:32:48,901 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) Executing: /bin/bash -c brctl show | grep cloudVirBr50
        2013-01-17 14:32:48,909 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) Exit value is 1
        2013-01-17 14:32:48,910 DEBUG [utils.script.Script] (agentRequest-Handler-5:null)
        2013-01-17 14:32:48,910 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/vm/network/vnet/modifyvlan.sh -v 50 -p eth1 -b breth1-50 -o add
        2013-01-17 14:32:48,963 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) Execution is successful.
        2013-01-17 14:32:48,963 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) Set name-type for VLAN subsystem. Should be visible in /proc/net/vlan/config

        Show
        Marcus Sorensen added a comment - So you started at 4.0... The one thing I don't see is your agent log. can you look in the agent log, when the host is freshly started and the agent connects, the first router or vm gets started up you should see something like: 2013-01-17 14:32:48,891 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) Execution is successful. 2013-01-17 14:32:48,892 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) Executing: /bin/sh -c brctl show|grep cloud0 2013-01-17 14:32:48,900 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) Execution is successful. 2013-01-17 14:32:48,901 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) nic= [Nic:Management-172.17.10.136-null] 2013-01-17 14:32:48,901 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) nic= [Nic:Public-192.168.100.129-vlan://50] 2013-01-17 14:32:48,901 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) creating a vlan dev and bridge for public traffic per traffic label cloudbr1 2013-01-17 14:32:48,901 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) Executing: /bin/bash -c brctl show | grep cloudVirBr50 2013-01-17 14:32:48,909 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) Exit value is 1 2013-01-17 14:32:48,910 DEBUG [utils.script.Script] (agentRequest-Handler-5:null) 2013-01-17 14:32:48,910 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/vm/network/vnet/modifyvlan.sh -v 50 -p eth1 -b breth1-50 -o add 2013-01-17 14:32:48,963 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) Execution is successful. 2013-01-17 14:32:48,963 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) Set name-type for VLAN subsystem. Should be visible in /proc/net/vlan/config
        Hide
        Richard Shevel added a comment -

        if the names of bridge have changed, why I'm not see error in the logs?

        agent.log
        2013-01-18 01:50:42,995 INFO [cloud.agent.Agent] (AgentShutdownThread:null) Stopping the agent: Reason = sig.kill
        2013-01-18 01:50:52,408 INFO [utils.component.ComponentLocator] (main:null) Unable to find components.xml
        2013-01-18 01:50:52,410 INFO [utils.component.ComponentLocator] (main:null) Skipping configuration using components.xml
        2013-01-18 01:50:52,410 INFO [cloud.agent.AgentShell] (main:null) Implementation Version is 4.0.1.20130109153237
        2013-01-18 01:50:52,410 INFO [cloud.agent.AgentShell] (main:null) agent.properties found at /etc/cloud/agent/agent.properties
        2013-01-18 01:50:52,411 INFO [cloud.agent.AgentShell] (main:null) Defaulting to using properties file for storage
        2013-01-18 01:50:52,413 INFO [cloud.agent.AgentShell] (main:null) Defaulting to the constant time backoff algorithm
        2013-01-18 01:50:52,476 INFO [cloud.agent.Agent] (main:null) id is 5
        2013-01-18 01:50:52,568 INFO [resource.virtualnetwork.VirtualRoutingResource] (main:null) VirtualRoutingResource _scriptDir to use: scripts/network/domr/kvm
        2013-01-18 01:51:02,360 INFO [kvm.resource.LibvirtComputingResource] (main:null) No libvirt.vif.driver specififed. Defaults to BridgeVifDriver.
        2013-01-18 01:51:02,385 INFO [cloud.agent.Agent] (main:null) Agent [id = 5 : type = LibvirtComputingResource : zone = 1 : pod = 1 : workers = 5 : host = 192.168.254.221 : port = 8250
        2013-01-18 01:51:02,393 INFO [utils.nio.NioClient] (Agent-Selector:null) Connecting to 192.168.254.221:8250
        2013-01-18 01:51:02,582 INFO [utils.nio.NioClient] (Agent-Selector:null) SSL: Handshake done
        2013-01-18 01:51:07,838 INFO [cloud.serializer.GsonHelper] (Agent-Handler-1:null) Default Builder inited.
        2013-01-18 01:51:07,901 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Proccess agent startup answer, agent id = 5
        2013-01-18 01:51:07,901 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Set agent id 5
        2013-01-18 01:51:07,905 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Startup Response Received: agent id = 5

        cat /etc/cloud/agent/agent.properties
        #Storage
        #Fri Jan 18 01:51:07 MSK 2013
        guest.network.device=cloudbr0
        private.network.device=cloudbrm
        port=8250
        resource=com.cloud.hypervisor.kvm.resource.LibvirtComputingResource
        pod=1
        zone=1
        guid=fe9c206e-e734-33ee-9f3f-db7251f4f4b3
        cluster=1
        public.network.device=cloudbr1
        local.storage.uuid=c22102e7-fb6c-4ca2-8e76-e17303441d24
        host=192.168.254.221
        LibvirtComputingResource.id=5

        Show
        Richard Shevel added a comment - if the names of bridge have changed, why I'm not see error in the logs? agent.log 2013-01-18 01:50:42,995 INFO [cloud.agent.Agent] (AgentShutdownThread:null) Stopping the agent: Reason = sig.kill 2013-01-18 01:50:52,408 INFO [utils.component.ComponentLocator] (main:null) Unable to find components.xml 2013-01-18 01:50:52,410 INFO [utils.component.ComponentLocator] (main:null) Skipping configuration using components.xml 2013-01-18 01:50:52,410 INFO [cloud.agent.AgentShell] (main:null) Implementation Version is 4.0.1.20130109153237 2013-01-18 01:50:52,410 INFO [cloud.agent.AgentShell] (main:null) agent.properties found at /etc/cloud/agent/agent.properties 2013-01-18 01:50:52,411 INFO [cloud.agent.AgentShell] (main:null) Defaulting to using properties file for storage 2013-01-18 01:50:52,413 INFO [cloud.agent.AgentShell] (main:null) Defaulting to the constant time backoff algorithm 2013-01-18 01:50:52,476 INFO [cloud.agent.Agent] (main:null) id is 5 2013-01-18 01:50:52,568 INFO [resource.virtualnetwork.VirtualRoutingResource] (main:null) VirtualRoutingResource _scriptDir to use: scripts/network/domr/kvm 2013-01-18 01:51:02,360 INFO [kvm.resource.LibvirtComputingResource] (main:null) No libvirt.vif.driver specififed. Defaults to BridgeVifDriver. 2013-01-18 01:51:02,385 INFO [cloud.agent.Agent] (main:null) Agent [id = 5 : type = LibvirtComputingResource : zone = 1 : pod = 1 : workers = 5 : host = 192.168.254.221 : port = 8250 2013-01-18 01:51:02,393 INFO [utils.nio.NioClient] (Agent-Selector:null) Connecting to 192.168.254.221:8250 2013-01-18 01:51:02,582 INFO [utils.nio.NioClient] (Agent-Selector:null) SSL: Handshake done 2013-01-18 01:51:07,838 INFO [cloud.serializer.GsonHelper] (Agent-Handler-1:null) Default Builder inited. 2013-01-18 01:51:07,901 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Proccess agent startup answer, agent id = 5 2013-01-18 01:51:07,901 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Set agent id 5 2013-01-18 01:51:07,905 INFO [cloud.agent.Agent] (Agent-Handler-2:null) Startup Response Received: agent id = 5 cat /etc/cloud/agent/agent.properties #Storage #Fri Jan 18 01:51:07 MSK 2013 guest.network.device=cloudbr0 private.network.device=cloudbrm port=8250 resource=com.cloud.hypervisor.kvm.resource.LibvirtComputingResource pod=1 zone=1 guid=fe9c206e-e734-33ee-9f3f-db7251f4f4b3 cluster=1 public.network.device=cloudbr1 local.storage.uuid=c22102e7-fb6c-4ca2-8e76-e17303441d24 host=192.168.254.221 LibvirtComputingResource.id=5
        Hide
        Richard Shevel added a comment -

        i turn on debug and :

        2013-01-18 01:57:36,194 INFO [cloud.agent.AgentShell] (main:null) Implementation Version is 4.0.1.20130109153237
        2013-01-18 01:57:36,194 INFO [cloud.agent.AgentShell] (main:null) agent.properties found at /etc/cloud/agent/agent.properties
        2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: guest.network.device
        2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: private.network.device
        2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: port
        2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: resource
        2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: pod
        2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: zone
        2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: guid
        2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: public.network.device
        2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: cluster
        2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: local.storage.uuid
        2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: LibvirtComputingResource.id
        2013-01-18 01:57:36,197 DEBUG [cloud.agent.AgentShell] (main:null) Found property: host
        2013-01-18 01:57:36,197 INFO [cloud.agent.AgentShell] (main:null) Defaulting to using properties file for storage
        2013-01-18 01:57:36,198 INFO [cloud.agent.AgentShell] (main:null) Defaulting to the constant time backoff algorithm
        2013-01-18 01:57:36,199 DEBUG [cloud.agent.AgentShell] (main:null) Checking to see if agent.pid exists.
        2013-01-18 01:57:36,208 DEBUG [cloud.utils.ProcessUtil] (main:null) Executing: bash -c echo $PPID
        2013-01-18 01:57:36,214 DEBUG [cloud.utils.ProcessUtil] (main:null) Execution is successful.
        2013-01-18 01:57:36,264 INFO [cloud.agent.Agent] (main:null) id is 5
        2013-01-18 01:57:36,265 DEBUG [cloud.resource.ServerResourceBase] (main:null) Retrieving network interface: cloudbrm
        2013-01-18 01:57:36,267 DEBUG [cloud.resource.ServerResourceBase] (main:null) Retrieving network interface: cloudbr1
        2013-01-18 01:57:36,268 DEBUG [cloud.resource.ServerResourceBase] (main:null) Unable to get network interface for cloudbr1
        2013-01-18 01:57:36,268 DEBUG [cloud.resource.ServerResourceBase] (main:null) Retrieving network interface: null
        2013-01-18 01:57:36,268 DEBUG [cloud.resource.ServerResourceBase] (main:null) Retrieving network interface: null
        2013-01-18 01:57:36,360 INFO [resource.virtualnetwork.VirtualRoutingResource] (main:null) VirtualRoutingResource _scriptDir to use: scripts/network/domr/kvm
        2013-01-18 01:57:36,361 DEBUG [utils.script.Script] (main:null) Looking for call_firewall.sh in the classpath
        2013-01-18 01:57:36,361 DEBUG [utils.script.Script] (main:null) System resource: null
        2013-01-18 01:57:36,361 DEBUG [utils.script.Script] (main:null) Looking for call_firewall.sh
        2013-01-18 01:57:36,361 DEBUG [utils.script.Script] (main:null) Current binaries reside at /usr/share/java

        2013-01-18 01:57:47,021 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: v-2-VM
        2013-01-18 01:57:47,022 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: i-11-293-VM
        2013-01-18 01:57:47,022 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: i-7-289-VM
        2013-01-18 01:57:47,022 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: r-291-VM
        2013-01-18 01:57:47,022 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: r-292-VM
        2013-01-18 01:57:47,022 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: i-3-271-VM
        2013-01-18 01:57:47,022 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: i-3-273-VM
        2013-01-18 01:57:47,022 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: s-264-VM
        2013-01-18 01:57:47,022 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: i-2-274-VM
        2013-01-18 01:57:51,805 DEBUG [kvm.resource.LibvirtCapXMLParser] (Agent-Handler-1:null) Found /usr/libexec/qemu-kvm as a suiteable emulator

        Show
        Richard Shevel added a comment - i turn on debug and : 2013-01-18 01:57:36,194 INFO [cloud.agent.AgentShell] (main:null) Implementation Version is 4.0.1.20130109153237 2013-01-18 01:57:36,194 INFO [cloud.agent.AgentShell] (main:null) agent.properties found at /etc/cloud/agent/agent.properties 2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: guest.network.device 2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: private.network.device 2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: port 2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: resource 2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: pod 2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: zone 2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: guid 2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: public.network.device 2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: cluster 2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: local.storage.uuid 2013-01-18 01:57:36,196 DEBUG [cloud.agent.AgentShell] (main:null) Found property: LibvirtComputingResource.id 2013-01-18 01:57:36,197 DEBUG [cloud.agent.AgentShell] (main:null) Found property: host 2013-01-18 01:57:36,197 INFO [cloud.agent.AgentShell] (main:null) Defaulting to using properties file for storage 2013-01-18 01:57:36,198 INFO [cloud.agent.AgentShell] (main:null) Defaulting to the constant time backoff algorithm 2013-01-18 01:57:36,199 DEBUG [cloud.agent.AgentShell] (main:null) Checking to see if agent.pid exists. 2013-01-18 01:57:36,208 DEBUG [cloud.utils.ProcessUtil] (main:null) Executing: bash -c echo $PPID 2013-01-18 01:57:36,214 DEBUG [cloud.utils.ProcessUtil] (main:null) Execution is successful. 2013-01-18 01:57:36,264 INFO [cloud.agent.Agent] (main:null) id is 5 2013-01-18 01:57:36,265 DEBUG [cloud.resource.ServerResourceBase] (main:null) Retrieving network interface: cloudbrm 2013-01-18 01:57:36,267 DEBUG [cloud.resource.ServerResourceBase] (main:null) Retrieving network interface: cloudbr1 2013-01-18 01:57:36,268 DEBUG [cloud.resource.ServerResourceBase] (main:null) Unable to get network interface for cloudbr1 2013-01-18 01:57:36,268 DEBUG [cloud.resource.ServerResourceBase] (main:null) Retrieving network interface: null 2013-01-18 01:57:36,268 DEBUG [cloud.resource.ServerResourceBase] (main:null) Retrieving network interface: null 2013-01-18 01:57:36,360 INFO [resource.virtualnetwork.VirtualRoutingResource] (main:null) VirtualRoutingResource _scriptDir to use: scripts/network/domr/kvm 2013-01-18 01:57:36,361 DEBUG [utils.script.Script] (main:null) Looking for call_firewall.sh in the classpath 2013-01-18 01:57:36,361 DEBUG [utils.script.Script] (main:null) System resource: null 2013-01-18 01:57:36,361 DEBUG [utils.script.Script] (main:null) Looking for call_firewall.sh 2013-01-18 01:57:36,361 DEBUG [utils.script.Script] (main:null) Current binaries reside at /usr/share/java 2013-01-18 01:57:47,021 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: v-2-VM 2013-01-18 01:57:47,022 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: i-11-293-VM 2013-01-18 01:57:47,022 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: i-7-289-VM 2013-01-18 01:57:47,022 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: r-291-VM 2013-01-18 01:57:47,022 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: r-292-VM 2013-01-18 01:57:47,022 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: i-3-271-VM 2013-01-18 01:57:47,022 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: i-3-273-VM 2013-01-18 01:57:47,022 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: s-264-VM 2013-01-18 01:57:47,022 DEBUG [kvm.resource.LibvirtComputingResource] (Agent-Handler-1:null) Detecting a new state but couldn't find a old state so adding it to the changes: i-2-274-VM 2013-01-18 01:57:51,805 DEBUG [kvm.resource.LibvirtCapXMLParser] (Agent-Handler-1:null) Found /usr/libexec/qemu-kvm as a suiteable emulator
        Hide
        Richard Shevel added a comment - - edited

        when i restarted VPC i see this in agent.log:

        2013-01-18 02:04:52,823 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful.
        2013-01-18 02:04:52,824 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.PlugNicCommand
        2013-01-18 02:04:52,892 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-2:null) nic=[Nic:Public-77.95.133.142-vlan://50]
        2013-01-18 02:04:52,892 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-2:null) Executing: /usr/lib64/cloud/common/scripts/vm/network/vnet/modifyvlan.sh -v 50 -p bond2 -o add
        2013-01-18 02:04:52,922 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-2:null) Execution is successful.
        2013-01-18 02:04:52,922 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-2:null) Set name-type for VLAN subsystem. Should be visible in /proc/net/vlan/config

        2013-01-18 02:04:53,084 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.routing.IpAssocVpcCommand
        2013-01-18 02:04:53,145 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c vlanid=$(brctl show |grep cloudVirBr50 |awk '

        {print $4}' | cut -s -d. -f 2);echo $vlanid
        2013-01-18 02:04:53,161 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful.
        2013-01-18 02:04:53,162 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh vpc_ipassoc.sh 169.254.2.223 -A -l 77.95.133.142 -c ethnull -g 77.95.133.129 -m 26 -n 77.95.133.128
        2013-01-18 02:04:53,298 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Execution is successful.
        2013-01-18 02:04:53,298 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Device "ethnull" does not exist.
        Cannot find device "ethnull"
        Error: argument "Table_ethnull" is wrong: "table" value is invalid

        Error: argument "Table_ethnull" is wrong: "table" value is invalid

        RTNETLINK answers: No such process

        2013-01-18 02:04:53,299 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.routing.SetSourceNatCommand
        2013-01-18 02:04:53,366 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c vlanid=$(brctl show |grep cloud0 |awk '{print $4}

        ' | cut -s -d. -f 2);echo $vlanid
        2013-01-18 02:04:53,383 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful.
        2013-01-18 02:04:53,383 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c vlanid=$(brctl show |grep cloudVirBr50 |awk '

        {print $4}

        ' | cut -s -d. -f 2);echo $vlanid
        2013-01-18 02:04:53,398 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful.
        2013-01-18 02:04:53,399 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh vpc_snat.sh 169.254.2.223 -A -l 77.95.133.142 -c eth2
        2013-01-18 02:04:53,517 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Execution is successful.
        2013-01-18 02:04:53,517 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) iptables: Bad rule (does a matching rule exist in that chain?).
        iptables: No chain/target/match by that name.

        2013-01-18 02:04:53,518 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.NetworkUsageCommand
        2013-01-18 02:04:53,518 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh netusage.sh 169.254.2.223 -c

        Show
        Richard Shevel added a comment - - edited when i restarted VPC i see this in agent.log: 2013-01-18 02:04:52,823 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful. 2013-01-18 02:04:52,824 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.PlugNicCommand 2013-01-18 02:04:52,892 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-2:null) nic= [Nic:Public-77.95.133.142-vlan://50] 2013-01-18 02:04:52,892 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-2:null) Executing: /usr/lib64/cloud/common/scripts/vm/network/vnet/modifyvlan.sh -v 50 -p bond2 -o add 2013-01-18 02:04:52,922 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-2:null) Execution is successful. 2013-01-18 02:04:52,922 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-2:null) Set name-type for VLAN subsystem. Should be visible in /proc/net/vlan/config 2013-01-18 02:04:53,084 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.routing.IpAssocVpcCommand 2013-01-18 02:04:53,145 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c vlanid=$(brctl show |grep cloudVirBr50 |awk ' {print $4}' | cut -s -d. -f 2);echo $vlanid 2013-01-18 02:04:53,161 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful. 2013-01-18 02:04:53,162 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh vpc_ipassoc.sh 169.254.2.223 -A -l 77.95.133.142 -c ethnull -g 77.95.133.129 -m 26 -n 77.95.133.128 2013-01-18 02:04:53,298 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Execution is successful. 2013-01-18 02:04:53,298 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Device "ethnull" does not exist. Cannot find device "ethnull" Error: argument "Table_ethnull" is wrong: "table" value is invalid Error: argument "Table_ethnull" is wrong: "table" value is invalid RTNETLINK answers: No such process 2013-01-18 02:04:53,299 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.routing.SetSourceNatCommand 2013-01-18 02:04:53,366 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c vlanid=$(brctl show |grep cloud0 |awk '{print $4} ' | cut -s -d. -f 2);echo $vlanid 2013-01-18 02:04:53,383 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful. 2013-01-18 02:04:53,383 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /bin/bash -c vlanid=$(brctl show |grep cloudVirBr50 |awk ' {print $4} ' | cut -s -d. -f 2);echo $vlanid 2013-01-18 02:04:53,398 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Execution is successful. 2013-01-18 02:04:53,399 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh vpc_snat.sh 169.254.2.223 -A -l 77.95.133.142 -c eth2 2013-01-18 02:04:53,517 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Execution is successful. 2013-01-18 02:04:53,517 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) iptables: Bad rule (does a matching rule exist in that chain?). iptables: No chain/target/match by that name. 2013-01-18 02:04:53,518 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.NetworkUsageCommand 2013-01-18 02:04:53,518 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-2:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh netusage.sh 169.254.2.223 -c
        Hide
        Marcus Sorensen added a comment - - edited

        Changed my mind. It works with the bonded interfaces I use in devcloud. What do you get if you run "vlanid=$(brctl show |grep cloudVirBr50 |awk '

        {print $4}

        ' | cut -s -d. -f 2);echo $vlanid" at the command line? Also include a 'brctl show" along with this.

        also while you're at it:

        ls /sys/devices/virtual/net/cloudVirBr50/brif | egrep "^bond|^eth"| cut -d . -f2

        Show
        Marcus Sorensen added a comment - - edited Changed my mind. It works with the bonded interfaces I use in devcloud. What do you get if you run "vlanid=$(brctl show |grep cloudVirBr50 |awk ' {print $4} ' | cut -s -d. -f 2);echo $vlanid" at the command line? Also include a 'brctl show" along with this. also while you're at it: ls /sys/devices/virtual/net/cloudVirBr50/brif | egrep "^bond|^eth"| cut -d . -f2
        Hide
        Marcus Sorensen added a comment -

        Richard, if you are willing, you can try moving /usr/share/java/cloud-plugin-hypervisor-kvm.jar, copying this one with debug code in its place (change name to match), and restarting agent. Afterward you should see some more info in the agent log when you trigger a router restart.

        http://marcus.mlsorensen.com/cloudstack-extras/cloud-plugin-hypervisor-kvm-4.0.1-incubating-SNAPSHOT.jar

        tail -f /var/log/cloud/agent/agent.log | egrep "IpAssoc|getVlanIdFromBridge"

        Show
        Marcus Sorensen added a comment - Richard, if you are willing, you can try moving /usr/share/java/cloud-plugin-hypervisor-kvm.jar, copying this one with debug code in its place (change name to match), and restarting agent. Afterward you should see some more info in the agent log when you trigger a router restart. http://marcus.mlsorensen.com/cloudstack-extras/cloud-plugin-hypervisor-kvm-4.0.1-incubating-SNAPSHOT.jar tail -f /var/log/cloud/agent/agent.log | egrep "IpAssoc|getVlanIdFromBridge"
        Hide
        Richard Shevel added a comment -

        [root@bh4 agent]# /bin/bash -c vlanid=$(brctl show |grep cloudVirBr50 |awk '

        {print $4}

        ' | cut -s -d. -f 2);echo $vlanid

        [root@bh4 agent]# cat /proc/net/vlan/config
        VLAN Dev name | VLAN ID
        Name-Type: VLAN_NAME_TYPE_RAW_PLUS_VID_NO_PAD
        bond1.40 | 40 | bond1
        bond2.50 | 50 | bond2
        bond1.700 | 700 | bond1
        bond1.947 | 947 | bond1
        bond1.813 | 813 | bond1
        bond1.504 | 504 | bond1
        bond1.598 | 598 | bond1
        bond1.936 | 936 | bond1

        [root@bh4 agent]# ls /sys/devices/virtual/net/cloudVirBr50/brif | egrep "^bond|^eth"| cut -d . -f2
        50

        [root@bh4 agent]# ls /sys/devices/virtual/net/cloudVirBr50/brif | cat
        bond2.50
        vnet11
        vnet15
        vnet2
        vnet5

        Show
        Richard Shevel added a comment - [root@bh4 agent] # /bin/bash -c vlanid=$(brctl show |grep cloudVirBr50 |awk ' {print $4} ' | cut -s -d. -f 2);echo $vlanid [root@bh4 agent] # cat /proc/net/vlan/config VLAN Dev name | VLAN ID Name-Type: VLAN_NAME_TYPE_RAW_PLUS_VID_NO_PAD bond1.40 | 40 | bond1 bond2.50 | 50 | bond2 bond1.700 | 700 | bond1 bond1.947 | 947 | bond1 bond1.813 | 813 | bond1 bond1.504 | 504 | bond1 bond1.598 | 598 | bond1 bond1.936 | 936 | bond1 [root@bh4 agent] # ls /sys/devices/virtual/net/cloudVirBr50/brif | egrep "^bond|^eth"| cut -d . -f2 50 [root@bh4 agent] # ls /sys/devices/virtual/net/cloudVirBr50/brif | cat bond2.50 vnet11 vnet15 vnet2 vnet5
        Hide
        Richard Shevel added a comment - - edited

        completed the installation of cloud-plugin-hypervisor-kvm-4.0.1-incubating-SNAPSHOT.jar. and restarted (Cloud-agent and router):

        [root@bh4 java]# cat /var/log/cloud/agent/agent.log | egrep "IpAssoc|getVlanIdFromBridge"
        2013-01-18 11:39:47,377 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) Request:Seq 5-1161625613: { Cmd , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 100111, [{"StartCommand":{"vm":{"id":292,"name":"r-292-VM","type":"DomainRouter","cpus":1,"speed":500,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"Debian GNU/Linux 5.0 (32-bit)","bootArgs":" vpccidr=10.4.4.0/24 domain=test1vpc dns1=8.8.8.8 dns2=8.8.4.4 template=domP name=r-292-VM eth0ip=169.254.0.244 eth0mask=255.255.0.0 type=vpcrouter disable_rp_filter=true","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"vncPassword":"5619bf8c760f7042","params":{},"uuid":"10291b7f-1521-476f-abb1-5eb04ac11b02","disks":[

        {"id":589,"name":"ROOT-292","mountPoint":"/vg0_md","path":"c2998ea2-5dbf-4722-bcb6-5dfaa288c33d","size":725811200,"type":"ROOT","storagePoolType":"CLVM","storagePoolUuid":"724141d8-75a9-4033-8209-2ce6a64fe12a","deviceId":0}

        ],"nics":[

        {"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"224e8e50-649b-44c1-9b63-a55e8bce10cd","ip":"169.254.0.244","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:00:f4","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false}

        ]},"wait":0}},{"check.CheckSshCommand":{"ip":"169.254.0.244","port":3922,"interval":6,"retries":100,"name":"r-292-VM","wait":0}},{"GetDomRVersionCmd":{"accessDetails":

        {"router.name":"r-292-VM","router.ip":"169.254.0.244"}

        ,"wait":0}},{},{"PlugNicCommand":{"nic":

        {"deviceId":1,"networkRateMbps":200,"defaultNic":true,"uuid":"f59a35e8-47ef-446a-b99d-0d3e5e79f510","ip":"77.95.133.142","netmask":"255.255.255.192","gateway":"77.95.133.129","mac":"06:bb:92:00:00:6e","dns1":"8.8.8.8","dns2":"8.8.4.4","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://50","isolationUri":"vlan://50","isSecurityGroupEnabled":false,"name":"cloudbr1"}

        ,"instanceName":"r-292-VM","wait":0}},{"routing.IpAssocVpcCommand":{"ipAddresses":[

        {"accountId":9,"publicIp":"77.95.133.142","sourceNat":true,"add":true,"oneToOneNat":false,"firstIP":false,"vlanId":"50","vlanGateway":"77.95.133.129","vlanNetmask":"255.255.255.192","vifMacAddress":"06:bb:92:00:00:6e","networkRate":200,"trafficType":"Public","networkName":"cloudbr1"}

        ],"accessDetails":

        {"router.guest.ip":"77.95.133.142","zone.network.type":"Advanced","router.name":"r-292-VM","router.ip":"169.254.0.244"}

        ,"wait":0}},{"routing.SetSourceNatCommand":{"ipAddress":

        {"accountId":9,"publicIp":"77.95.133.142","sourceNat":true,"add":true,"oneToOneNat":false,"firstIP":false,"vlanId":"50","vlanGateway":"77.95.133.129","vlanNetmask":"255.255.255.192","vifMacAddress":"06:bb:92:00:00:6e","networkRate":200,"trafficType":"Public","networkName":"cloudbr1"}

        ,"add":true,"accessDetails":

        {"zone.network.type":"Advanced","router.name":"r-292-VM","router.ip":"169.254.0.244"}

        ,"wait":0}},{}] }
        2013-01-18 11:40:23,379 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) Processing command: com.cloud.agent.api.routing.IpAssocVpcCommand
        2013-01-18 11:40:23,451 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) IpAssocVpcCommand:LinkLocal is on dev eth0
        2013-01-18 11:40:23,466 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) getVlanIdFromBridge: found vlanId 50 504 from brctl for bridge cloudVirBr50
        2013-01-18 11:40:23,467 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) IpAssocVpcCommand:dev eth1 on bridge cloudVirBr50 is for vlan50 504
        2013-01-18 11:40:23,482 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) getVlanIdFromBridge: found vlanId 50 504 from brctl for bridge cloudVirBr50
        2013-01-18 11:40:23,482 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) IpAssocVpcCommand: ip 77.95.133.142 is on vlan 50 according to management server
        2013-01-18 11:40:23,482 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) IpAssocVpcCommand: nicName for ip 77.95.133.142 in router is ethnull
        2013-01-18 11:40:23,700 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) getVlanIdFromBridge: found nothing, returning null
        2013-01-18 11:40:23,714 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) getVlanIdFromBridge: found vlanId 50 504 from brctl for bridge cloudVirBr50
        2013-01-18 11:40:23,932 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) Seq 5-1161625613: { Ans: , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 110, [{"StartAnswer":{"vm":{"id":292,"name":"r-292-VM","type":"DomainRouter","cpus":1,"speed":500,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"Debian GNU/Linux 5.0 (32-bit)","bootArgs":" vpccidr=10.4.4.0/24 domain=test1vpc dns1=8.8.8.8 dns2=8.8.4.4 template=domP name=r-292-VM eth0ip=169.254.0.244 eth0mask=255.255.0.0 type=vpcrouter disable_rp_filter=true","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"vncPassword":"5619bf8c760f7042","params":{},"uuid":"10291b7f-1521-476f-abb1-5eb04ac11b02","disks":[

        {"id":589,"name":"ROOT-292","mountPoint":"/vg0_md","path":"c2998ea2-5dbf-4722-bcb6-5dfaa288c33d","size":725811200,"type":"ROOT","storagePoolType":"CLVM","storagePoolUuid":"724141d8-75a9-4033-8209-2ce6a64fe12a","deviceId":0}

        ],"nics":[

        {"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"224e8e50-649b-44c1-9b63-a55e8bce10cd","ip":"169.254.0.244","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:00:f4","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false}

        ]},"result":true,"wait":0}},{"check.CheckSshAnswer":{"result":true,"wait":0}},{"GetDomRVersionAnswer":{"templateVersion":"Cloudstack Release 3.0 Mon Feb 6 15:10:04 PST 2012","scriptsVersion":"4326a8c20c6aca3cadca17d2f0099a57","result":true,"details":"Cloudstack Release 3.0 Mon Feb 6 15:10:04 PST 2012&4326a8c20c6aca3cadca17d2f0099a57","wait":0}},{"NetworkUsageAnswer":{"routerName":"r-292-VM","bytesSent":0,"bytesReceived":0,"result":true,"wait":0}},{"PlugNicAnswer":{"result":true,"details":"success","wait":0}},{"routing.IpAssocAnswer":{"results":["77.95.133.142 - success"],"result":true,"wait":0}},{"routing.SetSourceNatAnswer":{"result":true,"details":"success","wait":0}},{"NetworkUsageAnswer":{"routerName":"r-292-VM","bytesSent":0,"bytesReceived":0,"result":true,"wait":0}}] }
        [root@bh4 java]#

        Show
        Richard Shevel added a comment - - edited completed the installation of cloud-plugin-hypervisor-kvm-4.0.1-incubating-SNAPSHOT.jar. and restarted (Cloud-agent and router): [root@bh4 java] # cat /var/log/cloud/agent/agent.log | egrep "IpAssoc|getVlanIdFromBridge" 2013-01-18 11:39:47,377 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) Request:Seq 5-1161625613: { Cmd , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 100111, [{"StartCommand":{"vm":{"id":292,"name":"r-292-VM","type":"DomainRouter","cpus":1,"speed":500,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"Debian GNU/Linux 5.0 (32-bit)","bootArgs":" vpccidr=10.4.4.0/24 domain=test1vpc dns1=8.8.8.8 dns2=8.8.4.4 template=domP name=r-292-VM eth0ip=169.254.0.244 eth0mask=255.255.0.0 type=vpcrouter disable_rp_filter=true","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"vncPassword":"5619bf8c760f7042","params":{},"uuid":"10291b7f-1521-476f-abb1-5eb04ac11b02","disks":[ {"id":589,"name":"ROOT-292","mountPoint":"/vg0_md","path":"c2998ea2-5dbf-4722-bcb6-5dfaa288c33d","size":725811200,"type":"ROOT","storagePoolType":"CLVM","storagePoolUuid":"724141d8-75a9-4033-8209-2ce6a64fe12a","deviceId":0} ],"nics":[ {"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"224e8e50-649b-44c1-9b63-a55e8bce10cd","ip":"169.254.0.244","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:00:f4","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false} ]},"wait":0}},{"check.CheckSshCommand":{"ip":"169.254.0.244","port":3922,"interval":6,"retries":100,"name":"r-292-VM","wait":0}},{"GetDomRVersionCmd":{"accessDetails": {"router.name":"r-292-VM","router.ip":"169.254.0.244"} ,"wait":0}},{},{"PlugNicCommand":{"nic": {"deviceId":1,"networkRateMbps":200,"defaultNic":true,"uuid":"f59a35e8-47ef-446a-b99d-0d3e5e79f510","ip":"77.95.133.142","netmask":"255.255.255.192","gateway":"77.95.133.129","mac":"06:bb:92:00:00:6e","dns1":"8.8.8.8","dns2":"8.8.4.4","broadcastType":"Vlan","type":"Public","broadcastUri":"vlan://50","isolationUri":"vlan://50","isSecurityGroupEnabled":false,"name":"cloudbr1"} ,"instanceName":"r-292-VM","wait":0}},{"routing.IpAssocVpcCommand":{"ipAddresses":[ {"accountId":9,"publicIp":"77.95.133.142","sourceNat":true,"add":true,"oneToOneNat":false,"firstIP":false,"vlanId":"50","vlanGateway":"77.95.133.129","vlanNetmask":"255.255.255.192","vifMacAddress":"06:bb:92:00:00:6e","networkRate":200,"trafficType":"Public","networkName":"cloudbr1"} ],"accessDetails": {"router.guest.ip":"77.95.133.142","zone.network.type":"Advanced","router.name":"r-292-VM","router.ip":"169.254.0.244"} ,"wait":0}},{"routing.SetSourceNatCommand":{"ipAddress": {"accountId":9,"publicIp":"77.95.133.142","sourceNat":true,"add":true,"oneToOneNat":false,"firstIP":false,"vlanId":"50","vlanGateway":"77.95.133.129","vlanNetmask":"255.255.255.192","vifMacAddress":"06:bb:92:00:00:6e","networkRate":200,"trafficType":"Public","networkName":"cloudbr1"} ,"add":true,"accessDetails": {"zone.network.type":"Advanced","router.name":"r-292-VM","router.ip":"169.254.0.244"} ,"wait":0}},{}] } 2013-01-18 11:40:23,379 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) Processing command: com.cloud.agent.api.routing.IpAssocVpcCommand 2013-01-18 11:40:23,451 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) IpAssocVpcCommand:LinkLocal is on dev eth0 2013-01-18 11:40:23,466 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) getVlanIdFromBridge: found vlanId 50 504 from brctl for bridge cloudVirBr50 2013-01-18 11:40:23,467 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) IpAssocVpcCommand:dev eth1 on bridge cloudVirBr50 is for vlan50 504 2013-01-18 11:40:23,482 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) getVlanIdFromBridge: found vlanId 50 504 from brctl for bridge cloudVirBr50 2013-01-18 11:40:23,482 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) IpAssocVpcCommand: ip 77.95.133.142 is on vlan 50 according to management server 2013-01-18 11:40:23,482 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) IpAssocVpcCommand: nicName for ip 77.95.133.142 in router is ethnull 2013-01-18 11:40:23,700 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) getVlanIdFromBridge: found nothing, returning null 2013-01-18 11:40:23,714 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-3:null) getVlanIdFromBridge: found vlanId 50 504 from brctl for bridge cloudVirBr50 2013-01-18 11:40:23,932 DEBUG [cloud.agent.Agent] (agentRequest-Handler-3:null) Seq 5-1161625613: { Ans: , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 110, [{"StartAnswer":{"vm":{"id":292,"name":"r-292-VM","type":"DomainRouter","cpus":1,"speed":500,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"Debian GNU/Linux 5.0 (32-bit)","bootArgs":" vpccidr=10.4.4.0/24 domain=test1vpc dns1=8.8.8.8 dns2=8.8.4.4 template=domP name=r-292-VM eth0ip=169.254.0.244 eth0mask=255.255.0.0 type=vpcrouter disable_rp_filter=true","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"vncPassword":"5619bf8c760f7042","params":{},"uuid":"10291b7f-1521-476f-abb1-5eb04ac11b02","disks":[ {"id":589,"name":"ROOT-292","mountPoint":"/vg0_md","path":"c2998ea2-5dbf-4722-bcb6-5dfaa288c33d","size":725811200,"type":"ROOT","storagePoolType":"CLVM","storagePoolUuid":"724141d8-75a9-4033-8209-2ce6a64fe12a","deviceId":0} ],"nics":[ {"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"224e8e50-649b-44c1-9b63-a55e8bce10cd","ip":"169.254.0.244","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:00:f4","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false} ]},"result":true,"wait":0}},{"check.CheckSshAnswer":{"result":true,"wait":0}},{"GetDomRVersionAnswer":{"templateVersion":"Cloudstack Release 3.0 Mon Feb 6 15:10:04 PST 2012","scriptsVersion":"4326a8c20c6aca3cadca17d2f0099a57","result":true,"details":"Cloudstack Release 3.0 Mon Feb 6 15:10:04 PST 2012&4326a8c20c6aca3cadca17d2f0099a57","wait":0}},{"NetworkUsageAnswer":{"routerName":"r-292-VM","bytesSent":0,"bytesReceived":0,"result":true,"wait":0}},{"PlugNicAnswer":{"result":true,"details":"success","wait":0}},{"routing.IpAssocAnswer":{"results": ["77.95.133.142 - success"] ,"result":true,"wait":0}},{"routing.SetSourceNatAnswer":{"result":true,"details":"success","wait":0}},{"NetworkUsageAnswer":{"routerName":"r-292-VM","bytesSent":0,"bytesReceived":0,"result":true,"wait":0}}] } [root@bh4 java] #
        Hide
        Richard Shevel added a comment -

        I also saw

        2013-01-18 11:40:49,941 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4: null) Processing command: com.cloud.agent.api.CheckS2SVpnConnectionsCommand
        2013-01-18 11:40:49,941 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-4: null) Executing: / usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh checkbatchs2svpn.sh 169.254.2.104
        2013-01-18 11:40:50,026 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-4: null) Exit value is 127
        2013-01-18 11:40:50,027 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-4: null) bash: / opt/cloud/bin/checkbatchs2svpn.sh: No such file or directory
        2013-01-18 11:40:50,028 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4: null) Seq 5-1161625619: {Ans:, MgmtId: 52239887788, via: 5, Ver: v1, Flags: 110, failed "," result ": false," wait ": 0}}]}

        bash: / opt/cloud/bin/checkbatchs2svpn.sh: No such file or directory
        inside in VR there is only checks2svpn.sh
        similar to the previous error with (/opt/cloud/bin/ipsectunnel)

        Show
        Richard Shevel added a comment - I also saw 2013-01-18 11:40:49,941 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4: null) Processing command: com.cloud.agent.api.CheckS2SVpnConnectionsCommand 2013-01-18 11:40:49,941 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-4: null) Executing: / usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh checkbatchs2svpn.sh 169.254.2.104 2013-01-18 11:40:50,026 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-4: null) Exit value is 127 2013-01-18 11:40:50,027 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-4: null) bash: / opt/cloud/bin/checkbatchs2svpn.sh: No such file or directory 2013-01-18 11:40:50,028 DEBUG [cloud.agent.Agent] (agentRequest-Handler-4: null) Seq 5-1161625619: {Ans:, MgmtId: 52239887788, via: 5, Ver: v1, Flags: 110, failed "," result ": false," wait ": 0}}]} bash: / opt/cloud/bin/checkbatchs2svpn.sh: No such file or directory inside in VR there is only checks2svpn.sh similar to the previous error with (/opt/cloud/bin/ipsectunnel)
        Hide
        Marcus Sorensen added a comment - - edited

        Thanks. I can probably have you a replacement jar soon, you can test and
        report back the fix and then we can submit it. Almost there.

        > [root@bh4 agent]# /bin/bash -c vlanid=$(brctl show |grep cloudVirBr50 |awk '

        {print $4}' | cut -s -d. -f 2);echo $vlanid

        You'll want to just run what I sent:

        vlanid=$(brctl show |grep cloudVirBr50 |awk '{print $4}

        ' | cut -s -d. -f
        2);echo $vlanid

        What we expect to respond with is 50. If I run what you have I get no
        output as well, even though everything works. I don't really like this
        code, there has to be a better way of getting the vlan from the bridge name
        without relying on the formatted output of brctl. If it does indeed return
        nothing, that will be the culprit of ethnull. But something in one of your
        later emails looked like it might be returning "50 504". Looks like it's grabbing
        more than the original author expected.

        > ls /sys/devices/virtual/net/cloudVirBr50/brif | egrep "^bond|^eth"| cut -d . -f2
        > 50

        Ok, so this might be a better alternative, it at least relies on the linux
        sys layout and not brctl's output. I'll look for other alternatives as well, but
        I think we're pretty much stuck with calling an external command for this.

        Edit to add missing relevant info that I quoted via email.

        Show
        Marcus Sorensen added a comment - - edited Thanks. I can probably have you a replacement jar soon, you can test and report back the fix and then we can submit it. Almost there. > [root@bh4 agent] # /bin/bash -c vlanid=$(brctl show |grep cloudVirBr50 |awk ' {print $4}' | cut -s -d. -f 2);echo $vlanid You'll want to just run what I sent: vlanid=$(brctl show |grep cloudVirBr50 |awk '{print $4} ' | cut -s -d. -f 2);echo $vlanid What we expect to respond with is 50. If I run what you have I get no output as well, even though everything works. I don't really like this code, there has to be a better way of getting the vlan from the bridge name without relying on the formatted output of brctl. If it does indeed return nothing, that will be the culprit of ethnull. But something in one of your later emails looked like it might be returning "50 504". Looks like it's grabbing more than the original author expected. > ls /sys/devices/virtual/net/cloudVirBr50/brif | egrep "^bond|^eth"| cut -d . -f2 > 50 Ok, so this might be a better alternative, it at least relies on the linux sys layout and not brctl's output. I'll look for other alternatives as well, but I think we're pretty much stuck with calling an external command for this. Edit to add missing relevant info that I quoted via email.
        Hide
        Marcus Sorensen added a comment -

        Ok, on the chechbatchs2svpn.sh I'll have to check with the people who put the VPN into the system vm, I don't know much about the VPN setup itself, I took the existing Xen code that calls into the systemvm and made KVM do it as well. So I'm not sure if that is a typo or if the batch one should exist.

        I see the error now, and I think my alternate way of pulling the vlan id will be more robust. I will get you a jar tomorrow to test. I'll put the other fixes in it as well.

        Show
        Marcus Sorensen added a comment - Ok, on the chechbatchs2svpn.sh I'll have to check with the people who put the VPN into the system vm, I don't know much about the VPN setup itself, I took the existing Xen code that calls into the systemvm and made KVM do it as well. So I'm not sure if that is a typo or if the batch one should exist. I see the error now, and I think my alternate way of pulling the vlan id will be more robust. I will get you a jar tomorrow to test. I'll put the other fixes in it as well.
        Hide
        Richard Shevel added a comment -

        Tnx Marcus. I will wait for a new jar.

        Show
        Richard Shevel added a comment - Tnx Marcus. I will wait for a new jar.
        Hide
        Marcus Sorensen added a comment -

        updated http://marcus.mlsorensen.com/cloudstack-extras/cloud-plugin-hypervisor-kvm-4.0.1-incubating-SNAPSHOT.jar

        also to get the ipsectunnel.sh fix you'd need to swap out your /usr/share/java/cloud-core.jar with http://marcus.mlsorensen.com/cloudstack-extras/cloud-core-4.0.1-incubating-SNAPSHOT.jar

        Still debug code in there, there were actually several changes I made where I could see that 'brctl | grep bridgename" or similar was used, where bridgename could match both cloudVirBr50 and cloudVirBr504 or cloudVirBr5004.

        Show
        Marcus Sorensen added a comment - updated http://marcus.mlsorensen.com/cloudstack-extras/cloud-plugin-hypervisor-kvm-4.0.1-incubating-SNAPSHOT.jar also to get the ipsectunnel.sh fix you'd need to swap out your /usr/share/java/cloud-core.jar with http://marcus.mlsorensen.com/cloudstack-extras/cloud-core-4.0.1-incubating-SNAPSHOT.jar Still debug code in there, there were actually several changes I made where I could see that 'brctl | grep bridgename" or similar was used, where bridgename could match both cloudVirBr50 and cloudVirBr504 or cloudVirBr5004.
        Hide
        Richard Shevel added a comment -

        i updated both .jar

        agent.log

        2013-01-18 23:21:52,605 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) Trying to connect to 169.254.0.22
        2013-01-18 23:21:52,607 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Ping command port succeeded for vm r-292-VM
        2013-01-18 23:21:52,607 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.GetDomRVersionCmd
        2013-01-18 23:21:52,607 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh get_template_version.sh 169.254.0.22
        2013-01-18 23:21:52,710 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) Execution is successful.
        2013-01-18 23:21:52,711 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.NetworkUsageCommand
        2013-01-18 23:21:52,711 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh netusage.sh 169.254.0.22 -c
        2013-01-18 23:21:52,820 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Execution is successful.
        2013-01-18 23:21:52,821 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.PlugNicCommand
        2013-01-18 23:21:52,899 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) nic=[Nic:Public-77.95.133.142-vlan://50]
        2013-01-18 23:21:52,899 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/vm/network/vnet/modifyvlan.sh -v 50 -p bond2 -o add
        2013-01-18 23:21:52,931 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) Execution is successful.
        2013-01-18 23:21:52,932 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) Set name-type for VLAN subsystem. Should be visible in /proc/net/vlan/config

        2013-01-18 23:21:53,104 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.routing.IpAssocVpcCommand
        2013-01-18 23:21:53,166 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) IpAssocVpcCommand:LinkLocal is on dev eth0
        2013-01-18 23:21:53,166 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) matchPifFileInDirectory: file name 'bond2.50'
        2013-01-18 23:21:53,166 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) NEWCODE:tested getVlanIdFromBridge
        2013-01-18 23:21:53,167 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) getVlanIdFromBridge: found vlanId 50 from sysfs for bridge cloudVirBr50
        2013-01-18 23:21:53,167 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) IpAssocVpcCommand:dev eth1 on bridge cloudVirBr50 is for vlan50
        2013-01-18 23:21:53,167 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) matchPifFileInDirectory: file name 'bond2.50'
        2013-01-18 23:21:53,167 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) NEWCODE:tested getVlanIdFromBridge
        2013-01-18 23:21:53,167 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) getVlanIdFromBridge: found vlanId 50 from sysfs for bridge cloudVirBr50
        2013-01-18 23:21:53,167 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) IpAssocVpcCommand: ip 77.95.133.142 is on vlan 50 according to management server
        2013-01-18 23:21:53,167 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) IpAssocVpcCommand: nicName for ip 77.95.133.142 in router is eth1
        2013-01-18 23:21:53,168 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh vpc_ipassoc.sh 169.254.0.22 -A -l 77.95.133.142 -c eth1
        -g 77.95.133.129 -m 26 -n 77.95.133.128
        2013-01-18 23:21:55,335 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) Execution is successful.
        2013-01-18 23:21:55,335 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) ARPING 77.95.133.142 from 77.95.133.142 eth1
        Sent 3 probes (3 broadcast(s))
        Received 0 response(s)

        2013-01-18 23:21:55,336 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.routing.SetSourceNatCommand
        2013-01-18 23:21:55,346 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) pubVlan id is 50 according to the command sent from server
        2013-01-18 23:21:55,402 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) router r-292-VM has plugged nic connected to bridge cloud0
        2013-01-18 23:21:55,402 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) matchPifFileInDirectory: file name 'vnet0'
        2013-01-18 23:21:55,402 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) matchPifFileInDirectory: file name 'vnet3'
        2013-01-18 23:21:55,402 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) matchPifFileInDirectory: file name 'vnet10'
        2013-01-18 23:21:55,402 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) matchPifFileInDirectory: file name 'vnet14'
        2013-01-18 23:21:55,402 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) NEWCODE:tested getVlanIdFromBridge
        2013-01-18 23:21:55,403 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) router r-292-VM has plugged nic connected to bridge cloudVirBr50
        2013-01-18 23:21:55,403 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) matchPifFileInDirectory: file name 'bond2.50'
        2013-01-18 23:21:55,403 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) NEWCODE:tested getVlanIdFromBridge
        2013-01-18 23:21:55,403 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) getVlanIdFromBridge: found vlanId 50 from sysfs for bridge cloudVirBr50
        2013-01-18 23:21:55,403 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) found out that device eth1is the router's public nic
        2013-01-18 23:21:55,403 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) SetSourceNatCommand passing to router dev eth1 as public interface
        2013-01-18 23:21:55,403 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh vpc_snat.sh 169.254.0.22 -A -l 77.95.133.142 -c eth1
        2013-01-18 23:21:55,519 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) Execution is successful.
        2013-01-18 23:21:55,520 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) iptables: Bad rule (does a matching rule exist in that chain?).
        iptables: No chain/target/match by that name.

        2013-01-18 23:21:55,520 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.NetworkUsageCommand
        2013-01-18 23:21:55,520 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh netusage.sh 169.254.0.22 -c
        2013-01-18 23:21:55,615 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Execution is successful.
        2013-01-18 23:21:55,520 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.NetworkUsageCommand
        2013-01-18 23:21:55,520 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh netusage.sh 169.254.0.22 -c
        2013-01-18 23:21:55,615 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Execution is successful.
        2013-01-18 23:21:55,624 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Seq 5-1912471567: { Ans: , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 110, [{"StartAnswer":{"vm":{"id":292,"name":"r-292-VM","type":"DomainRouter","cpus":1
        "speed":500,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"Debian GNU/Linux 5.0 (32-bit)","bootArgs":" vpccidr=10.4.4.0/24 domain=test1vpc dns1=8.8.8.8 dns2=8.8.4.4 template=domP name=r-292-VM eth0ip=169.254.0.22 eth0mask=255
        255.0.0 type=vpcrouter disable_rp_filter=true","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"vncPassword":"5619bf8c760f7042","params":{},"uuid":"10291b7f-1521-476f-abb1-5eb04ac11b02","disks":[

        {"id":589,"name":"ROOT-292","moun Point":"/vg0_md","path":"c2998ea2-5dbf-4722-bcb6-5dfaa288c33d","size":725811200,"type":"ROOT","storagePoolType":"CLVM","storagePoolUuid":"724141d8-75a9-4033-8209-2ce6a64fe12a","deviceId":0}

        ],"nics":[

        {"deviceId":0,"networkRateMbps":-1,"def ultNic":false,"uuid":"224e8e50-649b-44c1-9b63-a55e8bce10cd","ip":"169.254.0.22","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:00:16","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false}

        ]},"resu
        t":true,"wait":0}},{"check.CheckSshAnswer":{"result":true,"wait":0}},{"GetDomRVersionAnswer":{"templateVersion":"Cloudstack Release 3.0 Mon Feb 6 15:10:04 PST 2012","scriptsVersion":"4326a8c20c6aca3cadca17d2f0099a57","result":true,"detail
        ":"Cloudstack Release 3.0 Mon Feb 6 15:10:04 PST 2012&4326a8c20c6aca3cadca17d2f0099a57","wait":0}},{"NetworkUsageAnswer":{"routerName":"r-292-VM","bytesSent":0,"bytesReceived":0,"result":true,"wait":0}},{"PlugNicAnswer":{"result":true,"de
        ails":"success","wait":0}},{"routing.IpAssocAnswer":{"results":["77.95.133.142 - success"],"result":true,"wait":0}},{"routing.SetSourceNatAnswer":{"result":true,"details":"success","wait":0}},{"NetworkUsageAnswer":{"routerName":"r-292-VM"
        "bytesSent":0,"bytesReceived":0,"result":true,"wait":0}}] }
        2013-01-18 23:21:55,634 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Request:Seq 5-1912471570: { Cmd , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 100111, [{"CheckS2SVpnConnectionsCommand":{"vpnIps":[],"accessDetails":

        {"route .name":"r-291-VM","router.ip":"169.254.2.104"}

        ,"wait":30}}] }
        2013-01-18 23:21:55,634 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.CheckS2SVpnConnectionsCommand
        2013-01-18 23:21:55,634 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh checkbatchs2svpn.sh 169.254.2.104
        2013-01-18 23:21:55,718 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Exit value is 127
        2013-01-18 23:21:55,718 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) bash: /opt/cloud/bin/checkbatchs2svpn.sh: No such file or directory

        into VR

        root@r-292-VM:~# ip a
        1: lo: <LOOPBACK,UP,LOWER_UP> mtu 16436 qdisc noqueue state UNKNOWN
        link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
        inet 127.0.0.1/8 scope host lo
        2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000
        link/ether 0e:00:a9:fe:00:16 brd ff:ff:ff:ff:ff:ff
        inet 169.254.0.22/16 brd 169.254.255.255 scope global eth0
        3: eth1: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000
        link/ether 06:bb:92:00:00:6e brd ff:ff:ff:ff:ff:ff
        inet 77.95.133.142/26 brd 77.95.133.191 scope global eth1

        Very good.

        I am concerned about this:
        2013-01-18 23:21:55,520 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) iptables: Bad rule (does a matching rule exist in that chain?).
        iptables: No chain/target/match by that name.

        and

        2013-01-18 23:21:55,718 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) bash: /opt/cloud/bin/checkbatchs2svpn.sh: No such file or directory

        i restarted VPN connection and his status was CONNECTED but in the log:
        2013-01-18 23:30:19,936 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.CheckS2SVpnConnectionsCommand
        2013-01-18 23:30:19,936 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh checkbatchs2svpn.sh 169.254.2.136 217.70.20.213
        2013-01-18 23:30:20,021 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Exit value is 127
        2013-01-18 23:30:20,022 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) bash: /opt/cloud/bin/checkbatchs2svpn.sh: No such file or directory
        2013-01-18 23:30:20,023 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Seq 5-1912471612: { Ans: , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 110, [{"CheckS2SVpnConnectionsAnswer":{"ipToConnected":{},"ipToDetail":{},"details":"
        heckS2SVpnConneciontsCommand failed","result":false,"wait":0}}] }

        Jan 18 19:29:32 r-291-VM kernel: [ 152.273876] padlock: VIA PadLock not detected.
        Jan 18 19:29:32 r-291-VM cloud: ipsectunnel.sh: waiting ipsec start...
        Jan 18 19:29:32 r-291-VM pluto: adjusting ipsec.d to /etc/ipsec.d
        Jan 18 19:29:33 r-291-VM cloud: ipsectunnel.sh: waiting ipsec start...
        Jan 18 19:29:33 r-291-VM cloud: ipsectunnel.sh: creating configuration for ipsec tunnel: left peer=77.95.133.141 left net=10.3.3.0/24 left gateway=77.95.133.129 right peer=217.70.20.213 right network=192.168.10.0/24 phase1 policy=3de
        md5 phase2 policy=3des-md5 secret=blablablalblabla
        Jan 18 19:29:33 r-291-VM cloud: ipsectunnel.sh: removing configuration for ipsec tunnel to 217.70.20.213
        Jan 18 19:29:33 r-291-VM kernel: [ 153.570932] alg: No test for authenc(hmac(md5),cbc(des3_ede)) (authenc(hmac(md5-generic),cbc(des3_ede-generic)))
        Jan 18 19:29:33 r-291-VM cloud: ipsectunnel.sh: done ipsec tunnel entry for right peer=217.70.20.213 right networks=192.168.10.0/24
        Jan 18 19:29:33 r-291-VM cloud: ipsectunnel.sh: checking connection status...
        Jan 18 19:29:33 r-291-VM cloud: ipsectunnel.sh: connect to remote successful

        Show
        Richard Shevel added a comment - i updated both .jar agent.log 2013-01-18 23:21:52,605 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) Trying to connect to 169.254.0.22 2013-01-18 23:21:52,607 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Ping command port succeeded for vm r-292-VM 2013-01-18 23:21:52,607 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.GetDomRVersionCmd 2013-01-18 23:21:52,607 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh get_template_version.sh 169.254.0.22 2013-01-18 23:21:52,710 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) Execution is successful. 2013-01-18 23:21:52,711 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.NetworkUsageCommand 2013-01-18 23:21:52,711 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh netusage.sh 169.254.0.22 -c 2013-01-18 23:21:52,820 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Execution is successful. 2013-01-18 23:21:52,821 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.PlugNicCommand 2013-01-18 23:21:52,899 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) nic= [Nic:Public-77.95.133.142-vlan://50] 2013-01-18 23:21:52,899 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/vm/network/vnet/modifyvlan.sh -v 50 -p bond2 -o add 2013-01-18 23:21:52,931 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) Execution is successful. 2013-01-18 23:21:52,932 DEBUG [kvm.resource.BridgeVifDriver] (agentRequest-Handler-5:null) Set name-type for VLAN subsystem. Should be visible in /proc/net/vlan/config 2013-01-18 23:21:53,104 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.routing.IpAssocVpcCommand 2013-01-18 23:21:53,166 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) IpAssocVpcCommand:LinkLocal is on dev eth0 2013-01-18 23:21:53,166 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) matchPifFileInDirectory: file name 'bond2.50' 2013-01-18 23:21:53,166 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) NEWCODE:tested getVlanIdFromBridge 2013-01-18 23:21:53,167 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) getVlanIdFromBridge: found vlanId 50 from sysfs for bridge cloudVirBr50 2013-01-18 23:21:53,167 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) IpAssocVpcCommand:dev eth1 on bridge cloudVirBr50 is for vlan50 2013-01-18 23:21:53,167 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) matchPifFileInDirectory: file name 'bond2.50' 2013-01-18 23:21:53,167 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) NEWCODE:tested getVlanIdFromBridge 2013-01-18 23:21:53,167 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) getVlanIdFromBridge: found vlanId 50 from sysfs for bridge cloudVirBr50 2013-01-18 23:21:53,167 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) IpAssocVpcCommand: ip 77.95.133.142 is on vlan 50 according to management server 2013-01-18 23:21:53,167 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) IpAssocVpcCommand: nicName for ip 77.95.133.142 in router is eth1 2013-01-18 23:21:53,168 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh vpc_ipassoc.sh 169.254.0.22 -A -l 77.95.133.142 -c eth1 -g 77.95.133.129 -m 26 -n 77.95.133.128 2013-01-18 23:21:55,335 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) Execution is successful. 2013-01-18 23:21:55,335 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) ARPING 77.95.133.142 from 77.95.133.142 eth1 Sent 3 probes (3 broadcast(s)) Received 0 response(s) 2013-01-18 23:21:55,336 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.routing.SetSourceNatCommand 2013-01-18 23:21:55,346 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) pubVlan id is 50 according to the command sent from server 2013-01-18 23:21:55,402 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) router r-292-VM has plugged nic connected to bridge cloud0 2013-01-18 23:21:55,402 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) matchPifFileInDirectory: file name 'vnet0' 2013-01-18 23:21:55,402 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) matchPifFileInDirectory: file name 'vnet3' 2013-01-18 23:21:55,402 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) matchPifFileInDirectory: file name 'vnet10' 2013-01-18 23:21:55,402 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) matchPifFileInDirectory: file name 'vnet14' 2013-01-18 23:21:55,402 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) NEWCODE:tested getVlanIdFromBridge 2013-01-18 23:21:55,403 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) router r-292-VM has plugged nic connected to bridge cloudVirBr50 2013-01-18 23:21:55,403 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) matchPifFileInDirectory: file name 'bond2.50' 2013-01-18 23:21:55,403 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) NEWCODE:tested getVlanIdFromBridge 2013-01-18 23:21:55,403 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) getVlanIdFromBridge: found vlanId 50 from sysfs for bridge cloudVirBr50 2013-01-18 23:21:55,403 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) found out that device eth1is the router's public nic 2013-01-18 23:21:55,403 INFO [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) SetSourceNatCommand passing to router dev eth1 as public interface 2013-01-18 23:21:55,403 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh vpc_snat.sh 169.254.0.22 -A -l 77.95.133.142 -c eth1 2013-01-18 23:21:55,519 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) Execution is successful. 2013-01-18 23:21:55,520 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) iptables: Bad rule (does a matching rule exist in that chain?). iptables: No chain/target/match by that name. 2013-01-18 23:21:55,520 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.NetworkUsageCommand 2013-01-18 23:21:55,520 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh netusage.sh 169.254.0.22 -c 2013-01-18 23:21:55,615 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Execution is successful. 2013-01-18 23:21:55,520 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Processing command: com.cloud.agent.api.NetworkUsageCommand 2013-01-18 23:21:55,520 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh netusage.sh 169.254.0.22 -c 2013-01-18 23:21:55,615 DEBUG [kvm.resource.LibvirtComputingResource] (agentRequest-Handler-5:null) Execution is successful. 2013-01-18 23:21:55,624 DEBUG [cloud.agent.Agent] (agentRequest-Handler-5:null) Seq 5-1912471567: { Ans: , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 110, [{"StartAnswer":{"vm":{"id":292,"name":"r-292-VM","type":"DomainRouter","cpus":1 "speed":500,"minRam":134217728,"maxRam":134217728,"arch":"x86_64","os":"Debian GNU/Linux 5.0 (32-bit)","bootArgs":" vpccidr=10.4.4.0/24 domain=test1vpc dns1=8.8.8.8 dns2=8.8.4.4 template=domP name=r-292-VM eth0ip=169.254.0.22 eth0mask=255 255.0.0 type=vpcrouter disable_rp_filter=true","rebootOnCrash":false,"enableHA":true,"limitCpuUse":false,"vncPassword":"5619bf8c760f7042","params":{},"uuid":"10291b7f-1521-476f-abb1-5eb04ac11b02","disks":[ {"id":589,"name":"ROOT-292","moun Point":"/vg0_md","path":"c2998ea2-5dbf-4722-bcb6-5dfaa288c33d","size":725811200,"type":"ROOT","storagePoolType":"CLVM","storagePoolUuid":"724141d8-75a9-4033-8209-2ce6a64fe12a","deviceId":0} ],"nics":[ {"deviceId":0,"networkRateMbps":-1,"def ultNic":false,"uuid":"224e8e50-649b-44c1-9b63-a55e8bce10cd","ip":"169.254.0.22","netmask":"255.255.0.0","gateway":"169.254.0.1","mac":"0e:00:a9:fe:00:16","broadcastType":"LinkLocal","type":"Control","isSecurityGroupEnabled":false} ]},"resu t":true,"wait":0}},{"check.CheckSshAnswer":{"result":true,"wait":0}},{"GetDomRVersionAnswer":{"templateVersion":"Cloudstack Release 3.0 Mon Feb 6 15:10:04 PST 2012","scriptsVersion":"4326a8c20c6aca3cadca17d2f0099a57","result":true,"detail ":"Cloudstack Release 3.0 Mon Feb 6 15:10:04 PST 2012&4326a8c20c6aca3cadca17d2f0099a57","wait":0}},{"NetworkUsageAnswer":{"routerName":"r-292-VM","bytesSent":0,"bytesReceived":0,"result":true,"wait":0}},{"PlugNicAnswer":{"result":true,"de ails":"success","wait":0}},{"routing.IpAssocAnswer":{"results": ["77.95.133.142 - success"] ,"result":true,"wait":0}},{"routing.SetSourceNatAnswer":{"result":true,"details":"success","wait":0}},{"NetworkUsageAnswer":{"routerName":"r-292-VM" "bytesSent":0,"bytesReceived":0,"result":true,"wait":0}}] } 2013-01-18 23:21:55,634 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Request:Seq 5-1912471570: { Cmd , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 100111, [{"CheckS2SVpnConnectionsCommand":{"vpnIps":[],"accessDetails": {"route .name":"r-291-VM","router.ip":"169.254.2.104"} ,"wait":30}}] } 2013-01-18 23:21:55,634 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.CheckS2SVpnConnectionsCommand 2013-01-18 23:21:55,634 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh checkbatchs2svpn.sh 169.254.2.104 2013-01-18 23:21:55,718 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Exit value is 127 2013-01-18 23:21:55,718 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) bash: /opt/cloud/bin/checkbatchs2svpn.sh: No such file or directory into VR root@r-292-VM:~# ip a 1: lo: <LOOPBACK,UP,LOWER_UP> mtu 16436 qdisc noqueue state UNKNOWN link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00 inet 127.0.0.1/8 scope host lo 2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000 link/ether 0e:00:a9:fe:00:16 brd ff:ff:ff:ff:ff:ff inet 169.254.0.22/16 brd 169.254.255.255 scope global eth0 3: eth1: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UNKNOWN qlen 1000 link/ether 06:bb:92:00:00:6e brd ff:ff:ff:ff:ff:ff inet 77.95.133.142/26 brd 77.95.133.191 scope global eth1 Very good. I am concerned about this: 2013-01-18 23:21:55,520 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) iptables: Bad rule (does a matching rule exist in that chain?). iptables: No chain/target/match by that name. and 2013-01-18 23:21:55,718 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) bash: /opt/cloud/bin/checkbatchs2svpn.sh: No such file or directory i restarted VPN connection and his status was CONNECTED but in the log: 2013-01-18 23:30:19,936 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Processing command: com.cloud.agent.api.CheckS2SVpnConnectionsCommand 2013-01-18 23:30:19,936 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh checkbatchs2svpn.sh 169.254.2.136 217.70.20.213 2013-01-18 23:30:20,021 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) Exit value is 127 2013-01-18 23:30:20,022 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-2:null) bash: /opt/cloud/bin/checkbatchs2svpn.sh: No such file or directory 2013-01-18 23:30:20,023 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) Seq 5-1912471612: { Ans: , MgmtId: 52239887788, via: 5, Ver: v1, Flags: 110, [{"CheckS2SVpnConnectionsAnswer":{"ipToConnected":{},"ipToDetail":{},"details":" heckS2SVpnConneciontsCommand failed","result":false,"wait":0}}] } Jan 18 19:29:32 r-291-VM kernel: [ 152.273876] padlock: VIA PadLock not detected. Jan 18 19:29:32 r-291-VM cloud: ipsectunnel.sh: waiting ipsec start... Jan 18 19:29:32 r-291-VM pluto: adjusting ipsec.d to /etc/ipsec.d Jan 18 19:29:33 r-291-VM cloud: ipsectunnel.sh: waiting ipsec start... Jan 18 19:29:33 r-291-VM cloud: ipsectunnel.sh: creating configuration for ipsec tunnel: left peer=77.95.133.141 left net=10.3.3.0/24 left gateway=77.95.133.129 right peer=217.70.20.213 right network=192.168.10.0/24 phase1 policy=3de md5 phase2 policy=3des-md5 secret=blablablalblabla Jan 18 19:29:33 r-291-VM cloud: ipsectunnel.sh: removing configuration for ipsec tunnel to 217.70.20.213 Jan 18 19:29:33 r-291-VM kernel: [ 153.570932] alg: No test for authenc(hmac(md5),cbc(des3_ede)) (authenc(hmac(md5-generic),cbc(des3_ede-generic))) Jan 18 19:29:33 r-291-VM cloud: ipsectunnel.sh: done ipsec tunnel entry for right peer=217.70.20.213 right networks=192.168.10.0/24 Jan 18 19:29:33 r-291-VM cloud: ipsectunnel.sh: checking connection status... Jan 18 19:29:33 r-291-VM cloud: ipsectunnel.sh: connect to remote successful
        Hide
        Sheng Yang added a comment -

        I've pushed checkbatchs2svpn.sh to the master and 4.0 branch. Sorry I missed it in the original commits...

        Show
        Sheng Yang added a comment - I've pushed checkbatchs2svpn.sh to the master and 4.0 branch. Sorry I missed it in the original commits...
        Hide
        Sheng Yang added a comment -

        The missing checkbatchs2svpn.sh won't affect the status of VPN connection, but it would disable the detection VPN connection state update feature(e.g. when you lost connection on VPN, the feature would change the VPN connection state to Disconnect).

        Show
        Sheng Yang added a comment - The missing checkbatchs2svpn.sh won't affect the status of VPN connection, but it would disable the detection VPN connection state update feature(e.g. when you lost connection on VPN, the feature would change the VPN connection state to Disconnect).
        Hide
        Marcus Sorensen added a comment -

        Thanks for testing this Richard. I will push these changes into master (minus the debug code), and maybe we should push this bug report back into 4.0.2 as target.

        The bad rule could mean a few things (maybe it already exists), looks like it was maybe the result of running the:

        2013-01-18 23:21:55,403 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh vpc_snat.sh 169.254.0.22 -A -l 77.95.133.142 -c eth1

        It looks like Anthony created that script. If you could "iptables -L -v -n" and "iptables -t nat -L -v -n" before and after that might tell us what's going on.

        Looking at the script it might mean nothing, because they attempt to delete the rule before adding it (presumably a safety measure to avoid duplication), and this error might get spit out due to that if the rule doesn't exist, even though the script succeeds in its duty.

        Show
        Marcus Sorensen added a comment - Thanks for testing this Richard. I will push these changes into master (minus the debug code), and maybe we should push this bug report back into 4.0.2 as target. The bad rule could mean a few things (maybe it already exists), looks like it was maybe the result of running the: 2013-01-18 23:21:55,403 DEBUG [resource.virtualnetwork.VirtualRoutingResource] (agentRequest-Handler-5:null) Executing: /usr/lib64/cloud/common/scripts/network/domr/router_proxy.sh vpc_snat.sh 169.254.0.22 -A -l 77.95.133.142 -c eth1 It looks like Anthony created that script. If you could "iptables -L -v -n" and "iptables -t nat -L -v -n" before and after that might tell us what's going on. Looking at the script it might mean nothing, because they attempt to delete the rule before adding it (presumably a safety measure to avoid duplication), and this error might get spit out due to that if the rule doesn't exist, even though the script succeeds in its duty.
        Hide
        Richard Shevel added a comment -

        Marcus, thanks for patch.
        It would be great if someone has make new rpm (jenkins.cloudstack.org) with all the patches that have been made here.

        I can't run "iptables -L -v -n" and "iptables -t nat -L -v -n" before and after, because at this time the router was restarted, and i don't have access to router.
        it's after reboot :

        root@r-291-VM:~# iptables -t nat -L -v -n
        Chain PREROUTING (policy ACCEPT 1091 packets, 61779 bytes)
        pkts bytes target prot opt in out source destination

        Chain POSTROUTING (policy ACCEPT 0 packets, 0 bytes)
        pkts bytes target prot opt in out source destination
        4 388 ACCEPT all – * eth1 0.0.0.0/0 0.0.0.0/0 mark match 0x525
        111 7118 SNAT all – * eth1 0.0.0.0/0 0.0.0.0/0 to:77.95.133.141
        0 0 SNAT all – * eth2 10.3.3.0/24 0.0.0.0/0 to:10.3.3.1

        Chain OUTPUT (policy ACCEPT 54 packets, 3774 bytes)
        pkts bytes target prot opt in out source destination
        root@r-291-VM:~#

        root@r-291-VM:~# iptables -L -v -n
        Chain INPUT (policy DROP 612 packets, 25118 bytes)
        pkts bytes target prot opt in out source destination
        8678 1193K NETWORK_STATS all – * * 0.0.0.0/0 0.0.0.0/0
        0 0 ACCEPT all – * * 0.0.0.0/0 224.0.0.18
        0 0 ACCEPT all – * * 0.0.0.0/0 225.0.0.50
        271 22801 ACCEPT icmp – * * 0.0.0.0/0 0.0.0.0/0
        5 293 ACCEPT all – lo * 0.0.0.0/0 0.0.0.0/0
        356 18512 ACCEPT tcp – eth0 * 0.0.0.0/0 0.0.0.0/0 state NEW tcp dpt:3922
        7392 1127K ACCEPT all – * * 0.0.0.0/0 0.0.0.0/0 state RELATED,ESTABLISHED
        0 0 ACCEPT udp – eth2 * 0.0.0.0/0 0.0.0.0/0 udp dpt:67
        75 4857 ACCEPT udp – eth2 * 0.0.0.0/0 10.3.3.1 udp dpt:53
        0 0 ACCEPT tcp – eth2 * 0.0.0.0/0 10.3.3.1 state NEW tcp dpt:80
        0 0 ACCEPT tcp – eth2 * 0.0.0.0/0 10.3.3.1 state NEW tcp dpt:8080
        0 0 ACCEPT udp – eth1 * 0.0.0.0/0 0.0.0.0/0 udp dpt:500
        0 0 ACCEPT udp – eth1 * 0.0.0.0/0 0.0.0.0/0 udp dpt:4500
        0 0 ACCEPT esp – eth1 * 0.0.0.0/0 0.0.0.0/0

        Chain FORWARD (policy DROP 0 packets, 0 bytes)
        pkts bytes target prot opt in out source destination
        2677 2847K NETWORK_STATS all – * * 0.0.0.0/0 0.0.0.0/0
        2604 2842K ACCEPT all – * * 0.0.0.0/0 0.0.0.0/0 state RELATED,ESTABLISHED
        73 4740 ACCEPT all – * * 10.3.3.0/24 !10.3.3.0/24
        0 0 ACL_INBOUND_eth2 all – * eth2 0.0.0.0/0 10.3.3.0/24

        Chain OUTPUT (policy ACCEPT 6194 packets, 920K bytes)
        pkts bytes target prot opt in out source destination
        7982 1208K NETWORK_STATS all – * * 0.0.0.0/0 0.0.0.0/0

        Chain ACL_INBOUND_eth2 (1 references)
        pkts bytes target prot opt in out source destination
        0 0 DROP all – * * 0.0.0.0/0 0.0.0.0/0

        Chain NETWORK_STATS (3 references)
        pkts bytes target prot opt in out source destination
        0 0 all – eth0 eth2 0.0.0.0/0 0.0.0.0/0
        0 0 all – eth2 eth0 0.0.0.0/0 0.0.0.0/0
        2014 2807K tcp – !eth0 eth2 0.0.0.0/0 0.0.0.0/0
        648 37975 tcp – eth2 !eth0 0.0.0.0/0 0.0.0.0/0

        Show
        Richard Shevel added a comment - Marcus, thanks for patch. It would be great if someone has make new rpm (jenkins.cloudstack.org) with all the patches that have been made here. I can't run "iptables -L -v -n" and "iptables -t nat -L -v -n" before and after, because at this time the router was restarted, and i don't have access to router. it's after reboot : root@r-291-VM:~# iptables -t nat -L -v -n Chain PREROUTING (policy ACCEPT 1091 packets, 61779 bytes) pkts bytes target prot opt in out source destination Chain POSTROUTING (policy ACCEPT 0 packets, 0 bytes) pkts bytes target prot opt in out source destination 4 388 ACCEPT all – * eth1 0.0.0.0/0 0.0.0.0/0 mark match 0x525 111 7118 SNAT all – * eth1 0.0.0.0/0 0.0.0.0/0 to:77.95.133.141 0 0 SNAT all – * eth2 10.3.3.0/24 0.0.0.0/0 to:10.3.3.1 Chain OUTPUT (policy ACCEPT 54 packets, 3774 bytes) pkts bytes target prot opt in out source destination root@r-291-VM:~# root@r-291-VM:~# iptables -L -v -n Chain INPUT (policy DROP 612 packets, 25118 bytes) pkts bytes target prot opt in out source destination 8678 1193K NETWORK_STATS all – * * 0.0.0.0/0 0.0.0.0/0 0 0 ACCEPT all – * * 0.0.0.0/0 224.0.0.18 0 0 ACCEPT all – * * 0.0.0.0/0 225.0.0.50 271 22801 ACCEPT icmp – * * 0.0.0.0/0 0.0.0.0/0 5 293 ACCEPT all – lo * 0.0.0.0/0 0.0.0.0/0 356 18512 ACCEPT tcp – eth0 * 0.0.0.0/0 0.0.0.0/0 state NEW tcp dpt:3922 7392 1127K ACCEPT all – * * 0.0.0.0/0 0.0.0.0/0 state RELATED,ESTABLISHED 0 0 ACCEPT udp – eth2 * 0.0.0.0/0 0.0.0.0/0 udp dpt:67 75 4857 ACCEPT udp – eth2 * 0.0.0.0/0 10.3.3.1 udp dpt:53 0 0 ACCEPT tcp – eth2 * 0.0.0.0/0 10.3.3.1 state NEW tcp dpt:80 0 0 ACCEPT tcp – eth2 * 0.0.0.0/0 10.3.3.1 state NEW tcp dpt:8080 0 0 ACCEPT udp – eth1 * 0.0.0.0/0 0.0.0.0/0 udp dpt:500 0 0 ACCEPT udp – eth1 * 0.0.0.0/0 0.0.0.0/0 udp dpt:4500 0 0 ACCEPT esp – eth1 * 0.0.0.0/0 0.0.0.0/0 Chain FORWARD (policy DROP 0 packets, 0 bytes) pkts bytes target prot opt in out source destination 2677 2847K NETWORK_STATS all – * * 0.0.0.0/0 0.0.0.0/0 2604 2842K ACCEPT all – * * 0.0.0.0/0 0.0.0.0/0 state RELATED,ESTABLISHED 73 4740 ACCEPT all – * * 10.3.3.0/24 !10.3.3.0/24 0 0 ACL_INBOUND_eth2 all – * eth2 0.0.0.0/0 10.3.3.0/24 Chain OUTPUT (policy ACCEPT 6194 packets, 920K bytes) pkts bytes target prot opt in out source destination 7982 1208K NETWORK_STATS all – * * 0.0.0.0/0 0.0.0.0/0 Chain ACL_INBOUND_eth2 (1 references) pkts bytes target prot opt in out source destination 0 0 DROP all – * * 0.0.0.0/0 0.0.0.0/0 Chain NETWORK_STATS (3 references) pkts bytes target prot opt in out source destination 0 0 all – eth0 eth2 0.0.0.0/0 0.0.0.0/0 0 0 all – eth2 eth0 0.0.0.0/0 0.0.0.0/0 2014 2807K tcp – !eth0 eth2 0.0.0.0/0 0.0.0.0/0 648 37975 tcp – eth2 !eth0 0.0.0.0/0 0.0.0.0/0
        Hide
        Marcus Sorensen added a comment -

        Ok, so I guess what you'd want is to test it. It looks like you do have the SNAT, so I think it's just bogus output from not being able to delete a non-existent rule. If you can bring up a VM on that VPC and it can get out, then the SNAT is working. In my test environment I see that error as well and the source nat is working.

        Show
        Marcus Sorensen added a comment - Ok, so I guess what you'd want is to test it. It looks like you do have the SNAT, so I think it's just bogus output from not being able to delete a non-existent rule. If you can bring up a VM on that VPC and it can get out, then the SNAT is working. In my test environment I see that error as well and the source nat is working.
        Hide
        Marcus Sorensen added a comment -

        Pushed to 4.0 branch as 23d55539763645d69fc8b35e393816108256d670, the code involved is different in master, so I've created a different set of code for that.

        Fixes created due to this bug report include:

        master commit b77503b5bd001d1038bb4cd79c04db7ca993e94e
        master commit e37a82375c1dd7631f37de1ed1b336f524d08c62
        4.0 commit 23d55539763645d69fc8b35e393816108256d670

        Show
        Marcus Sorensen added a comment - Pushed to 4.0 branch as 23d55539763645d69fc8b35e393816108256d670, the code involved is different in master, so I've created a different set of code for that. Fixes created due to this bug report include: master commit b77503b5bd001d1038bb4cd79c04db7ca993e94e master commit e37a82375c1dd7631f37de1ed1b336f524d08c62 4.0 commit 23d55539763645d69fc8b35e393816108256d670
        Hide
        Marcus Sorensen added a comment -

        customer tested fix

        Show
        Marcus Sorensen added a comment - customer tested fix

          People

          • Assignee:
            Marcus Sorensen
            Reporter:
            Richard Shevel
          • Votes:
            0 Vote for this issue
            Watchers:
            7 Start watching this issue

            Dates

            • Created:
              Updated:
              Resolved:

              Development