VPC Issue with CS 4.1/KVM/Openvswitch

2013-07-23 Thread Dinu Arateanu
Hello,

I've been testing Cloudstack 4.1 with KVM/Openvswitch networking. When trying 
to add a VPC, the VR's public interface default route was not assigned 
correctly, nor the source nat. Cloudstack reports the VPC is created 
successfully, however the VR is left in an "incomplete" state. Looking through 
the agent logs I found: 

2013-07-19 16:39:20,961 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) 
Processing command: com.cloud.agent.api.PlugNicCommand
2013-07-19 16:39:20,970 DEBUG [kvm.resource.OvsVifDriver] 
(agentRequest-Handler-2:null) plugging nic=[Nic:Public-192.168.1.68-vlan://32]
2013-07-19 16:39:20,970 DEBUG [kvm.resource.OvsVifDriver] 
(agentRequest-Handler-2:null) creating a vlan dev and bridge for public traffic 
per traffic label vswitch0
2013-07-19 16:39:21,116 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) 
Processing command: com.cloud.agent.api.routing.IpAssocVpcCommand
2013-07-19 16:39:21,126 DEBUG [resource.virtualnetwork.VirtualRoutingResource] 
(agentRequest-Handler-2:null) Executing: 
/usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh 
vpc_ipassoc.sh 169.254.2.23  -A  -l 192.168.1.68 -c ethnull -g 192.168.1.1 -m 
24 -n 192.168.1.0
2013-07-19 16:39:29,107 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) Executing: 
/usr/share/cloudstack-common/scripts/vm/network/security_group.py 
get_rule_logs_for_vms
2013-07-19 16:39:29,233 DEBUG [kvm.resource.LibvirtComputingResource] 
(UgentTask-5:null) Execution is successful.
2013-07-19 16:39:29,235 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending 
ping: Seq 7-103:  { Cmd , MgmtId: -1, via: 7, Ver: v1, Flags: 11, 
[{"PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":7,"wait":0}}]
 }
2013-07-19 16:39:29,243 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null) 
Received response: Seq 7-103:  { Ans: , MgmtId: 112938636298, via: 7, Ver: v1, 
Flags: 100010, 
[{"PingAnswer":{"_command":{"hostType":"Routing","hostId":7,"wait":0},"result":true,"wait":0}}]
 }
2013-07-19 16:39:38,707 DEBUG [resource.virtualnetwork.VirtualRoutingResource] 
(agentRequest-Handler-2:null) Execution is successful.
2013-07-19 16:39:38,708 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-07-19 16:39:38,709 DEBUG [cloud.agent.Agent] (agentRequest-Handler-2:null) 
Processing command: com.cloud.agent.api.routing.SetSourceNatCommand
2013-07-19 16:39:38,719 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-2:null) failing to get physical interface from 
bridgecloud0, did not find an eth*, bond*, or vlan* in 
/sys/devices/virtual/net/cloud0/brif
2013-07-19 16:39:38,719 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-2:null) failed to get vlan id from bridge cloud0attached 
to physical interface
2013-07-19 16:39:38,719 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-2:null) failing to get physical interface from 
bridgevswitch0, did not find an eth*, bond*, or vlan* in 
/sys/devices/virtual/net/vswitch0/brif
2013-07-19 16:39:38,719 DEBUG [kvm.resource.LibvirtComputingResource] 
(agentRequest-Handler-2:null) failed to get vlan id from bridge 
vswitch0attached to physical interface
2013-07-19 16:39:38,719 DEBUG [resource.virtualnetwork.VirtualRoutingResource] 
(agentRequest-Handler-2:null) Executing: 
/usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh vpc_snat.sh 
169.254.2.23  -A  -l 192.168.1.68 -c eth2
2013-07-19 16:39:38,947 DEBUG [resource.virtualnetwork.VirtualRoutingResource] 
(agentRequest-Handler-2:null) Execution is successful.
2013-07-19 16:39:38,948 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.


Cloudstack is configured with advanced networking. Tags for physical networks
- vswitch0 for public & guest traffic
- vif9 for storage traffic
- vif8 for management traffic

Openvswitch configuration: 
# ovs-vsctl show

Bridge "vswitch1"
Port "vswitch1"
Interface "vswitch1"
type: internal
Port "eth1"
Interface "eth1"
Port "vif9"
tag: 9
Interface "vif9"
type: internal
Bridge "vswitch0"
Port "vnet1"
tag: 32
Interface "vnet1"
Port "vswitch0"
Interface "vswitch0"
type: internal
Port "vif8"
tag: 8
Interface "vif8"
type: internal
Port "eth0"
Interface "eth0"
Bridge "cloud0"
Port "vnet0"
  

Re: VPC Issue with CS 4.1/KVM/Openvswitch

2013-08-01 Thread Ahmad Emneina
I can only guess this to be a bug. I'd file that and probably raise it to 
critical since this seems to bet key functionality broken. Have you tried this 
with Cloudstack 4.2 that's nearing release, and you might be able to get it 
fixed there.

Ahmad

On Jul 23, 2013, at 10:07 AM, Dinu Arateanu  wrote:

> Hello,
> 
> I've been testing Cloudstack 4.1 with KVM/Openvswitch networking. When trying 
> to add a VPC, the VR's public interface default route was not assigned 
> correctly, nor the source nat. Cloudstack reports the VPC is created 
> successfully, however the VR is left in an "incomplete" state. Looking 
> through the agent logs I found: 
> 
> 2013-07-19 16:39:20,961 DEBUG [cloud.agent.Agent] 
> (agentRequest-Handler-2:null) Processing command: 
> com.cloud.agent.api.PlugNicCommand
> 2013-07-19 16:39:20,970 DEBUG [kvm.resource.OvsVifDriver] 
> (agentRequest-Handler-2:null) plugging nic=[Nic:Public-192.168.1.68-vlan://32]
> 2013-07-19 16:39:20,970 DEBUG [kvm.resource.OvsVifDriver] 
> (agentRequest-Handler-2:null) creating a vlan dev and bridge for public 
> traffic per traffic label vswitch0
> 2013-07-19 16:39:21,116 DEBUG [cloud.agent.Agent] 
> (agentRequest-Handler-2:null) Processing command: 
> com.cloud.agent.api.routing.IpAssocVpcCommand
> 2013-07-19 16:39:21,126 DEBUG 
> [resource.virtualnetwork.VirtualRoutingResource] 
> (agentRequest-Handler-2:null) Executing: 
> /usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh 
> vpc_ipassoc.sh 169.254.2.23  -A  -l 192.168.1.68 -c ethnull -g 192.168.1.1 -m 
> 24 -n 192.168.1.0
> 2013-07-19 16:39:29,107 DEBUG [kvm.resource.LibvirtComputingResource] 
> (UgentTask-5:null) Executing: 
> /usr/share/cloudstack-common/scripts/vm/network/security_group.py 
> get_rule_logs_for_vms
> 2013-07-19 16:39:29,233 DEBUG [kvm.resource.LibvirtComputingResource] 
> (UgentTask-5:null) Execution is successful.
> 2013-07-19 16:39:29,235 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending 
> ping: Seq 7-103:  { Cmd , MgmtId: -1, via: 7, Ver: v1, Flags: 11, 
> [{"PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":7,"wait":0}}]
>  }
> 2013-07-19 16:39:29,243 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null) 
> Received response: Seq 7-103:  { Ans: , MgmtId: 112938636298, via: 7, Ver: 
> v1, Flags: 100010, 
> [{"PingAnswer":{"_command":{"hostType":"Routing","hostId":7,"wait":0},"result":true,"wait":0}}]
>  }
> 2013-07-19 16:39:38,707 DEBUG 
> [resource.virtualnetwork.VirtualRoutingResource] 
> (agentRequest-Handler-2:null) Execution is successful.
> 2013-07-19 16:39:38,708 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-07-19 16:39:38,709 DEBUG [cloud.agent.Agent] 
> (agentRequest-Handler-2:null) Processing command: 
> com.cloud.agent.api.routing.SetSourceNatCommand
> 2013-07-19 16:39:38,719 DEBUG [kvm.resource.LibvirtComputingResource] 
> (agentRequest-Handler-2:null) failing to get physical interface from 
> bridgecloud0, did not find an eth*, bond*, or vlan* in 
> /sys/devices/virtual/net/cloud0/brif
> 2013-07-19 16:39:38,719 DEBUG [kvm.resource.LibvirtComputingResource] 
> (agentRequest-Handler-2:null) failed to get vlan id from bridge 
> cloud0attached to physical interface
> 2013-07-19 16:39:38,719 DEBUG [kvm.resource.LibvirtComputingResource] 
> (agentRequest-Handler-2:null) failing to get physical interface from 
> bridgevswitch0, did not find an eth*, bond*, or vlan* in 
> /sys/devices/virtual/net/vswitch0/brif
> 2013-07-19 16:39:38,719 DEBUG [kvm.resource.LibvirtComputingResource] 
> (agentRequest-Handler-2:null) failed to get vlan id from bridge 
> vswitch0attached to physical interface
> 2013-07-19 16:39:38,719 DEBUG 
> [resource.virtualnetwork.VirtualRoutingResource] 
> (agentRequest-Handler-2:null) Executing: 
> /usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh vpc_snat.sh 
> 169.254.2.23  -A  -l 192.168.1.68 -c eth2
> 2013-07-19 16:39:38,947 DEBUG 
> [resource.virtualnetwork.VirtualRoutingResource] 
> (agentRequest-Handler-2:null) Execution is successful.
> 2013-07-19 16:39:38,948 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.
> 
> 
> Cloudstack is configured with advanced networking. Tags for physical networks
> - vswitch0 for public & guest traffic
> - vif9 for storage traffic
> - vif8 for management traffic
> 
> Openvswitch configuration: 
> # ovs-vsctl show
> 
>Bridge "vswitch1"
>Port "vswitch1"
>Interface "vswitch1"
>type: internal
>Port "eth1

Re: VPC Issue with CS 4.1/KVM/Openvswitch

2013-08-01 Thread Chiradeep Vittal
Check this thread
http://markmail.org/thread/gaxuprs6vtifsybk


On 7/23/13 10:37 PM, "Dinu Arateanu"  wrote:

>Hello,
>
>I've been testing Cloudstack 4.1 with KVM/Openvswitch networking. When
>trying to add a VPC, the VR's public interface default route was not
>assigned correctly, nor the source nat. Cloudstack reports the VPC is
>created successfully, however the VR is left in an "incomplete" state.
>Looking through the agent logs I found:
>
>2013-07-19 16:39:20,961 DEBUG [cloud.agent.Agent]
>(agentRequest-Handler-2:null) Processing command:
>com.cloud.agent.api.PlugNicCommand
>2013-07-19 16:39:20,970 DEBUG [kvm.resource.OvsVifDriver]
>(agentRequest-Handler-2:null) plugging
>nic=[Nic:Public-192.168.1.68-vlan://32]
>2013-07-19 16:39:20,970 DEBUG [kvm.resource.OvsVifDriver]
>(agentRequest-Handler-2:null) creating a vlan dev and bridge for public
>traffic per traffic label vswitch0
>2013-07-19 16:39:21,116 DEBUG [cloud.agent.Agent]
>(agentRequest-Handler-2:null) Processing command:
>com.cloud.agent.api.routing.IpAssocVpcCommand
>2013-07-19 16:39:21,126 DEBUG
>[resource.virtualnetwork.VirtualRoutingResource]
>(agentRequest-Handler-2:null) Executing:
>/usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh
>vpc_ipassoc.sh 169.254.2.23  -A  -l 192.168.1.68 -c ethnull -g
>192.168.1.1 -m 24 -n 192.168.1.0
>2013-07-19 16:39:29,107 DEBUG [kvm.resource.LibvirtComputingResource]
>(UgentTask-5:null) Executing:
>/usr/share/cloudstack-common/scripts/vm/network/security_group.py
>get_rule_logs_for_vms
>2013-07-19 16:39:29,233 DEBUG [kvm.resource.LibvirtComputingResource]
>(UgentTask-5:null) Execution is successful.
>2013-07-19 16:39:29,235 DEBUG [cloud.agent.Agent] (UgentTask-5:null)
>Sending ping: Seq 7-103:  { Cmd , MgmtId: -1, via: 7, Ver: v1, Flags: 11,
>[{"PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{},"_g
>atewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId
>":7,"wait":0}}] }
>2013-07-19 16:39:29,243 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null)
>Received response: Seq 7-103:  { Ans: , MgmtId: 112938636298, via: 7,
>Ver: v1, Flags: 100010,
>[{"PingAnswer":{"_command":{"hostType":"Routing","hostId":7,"wait":0},"res
>ult":true,"wait":0}}] }
>2013-07-19 16:39:38,707 DEBUG
>[resource.virtualnetwork.VirtualRoutingResource]
>(agentRequest-Handler-2:null) Execution is successful.
>2013-07-19 16:39:38,708 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-07-19 16:39:38,709 DEBUG [cloud.agent.Agent]
>(agentRequest-Handler-2:null) Processing command:
>com.cloud.agent.api.routing.SetSourceNatCommand
>2013-07-19 16:39:38,719 DEBUG [kvm.resource.LibvirtComputingResource]
>(agentRequest-Handler-2:null) failing to get physical interface from
>bridgecloud0, did not find an eth*, bond*, or vlan* in
>/sys/devices/virtual/net/cloud0/brif
>2013-07-19 16:39:38,719 DEBUG [kvm.resource.LibvirtComputingResource]
>(agentRequest-Handler-2:null) failed to get vlan id from bridge
>cloud0attached to physical interface
>2013-07-19 16:39:38,719 DEBUG [kvm.resource.LibvirtComputingResource]
>(agentRequest-Handler-2:null) failing to get physical interface from
>bridgevswitch0, did not find an eth*, bond*, or vlan* in
>/sys/devices/virtual/net/vswitch0/brif
>2013-07-19 16:39:38,719 DEBUG [kvm.resource.LibvirtComputingResource]
>(agentRequest-Handler-2:null) failed to get vlan id from bridge
>vswitch0attached to physical interface
>2013-07-19 16:39:38,719 DEBUG
>[resource.virtualnetwork.VirtualRoutingResource]
>(agentRequest-Handler-2:null) Executing:
>/usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh
>vpc_snat.sh 169.254.2.23  -A  -l 192.168.1.68 -c eth2
>2013-07-19 16:39:38,947 DEBUG
>[resource.virtualnetwork.VirtualRoutingResource]
>(agentRequest-Handler-2:null) Execution is successful.
>2013-07-19 16:39:38,948 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.
>
>
>Cloudstack is configured with advanced networking. Tags for physical
>networks
>- vswitch0 for public & guest traffic
>- vif9 for storage traffic
>- vif8 for management traffic
>
>Openvswitch configuration:
># ovs-vsctl show
>
>Bridge "vswitch1"
>Port "vswitch1"
>Interface "vswitch1"
>type: internal
>Port "eth1"
>Interface "eth1"
>Port "vif9"
>tag: 9
>Interface "vif9"
>type: internal
>Bridge "vswitch0"
>Port "vnet1"
>tag: 32
>Interface "vnet1"
>Port "vswitch0"
>Interface "vswitch0"
>type: internal
>Port 

Re: VPC Issue with CS 4.1/KVM/Openvswitch

2013-08-22 Thread Dinu Arateanu
I did file it - https://issues.apache.org/jira/browse/CLOUDSTACK-3783

I checked the code - the culprit seems to be a function called 
getVlanIdFromBridge() that doesn't take into account the type of networking 
that exists on the host. That particular code tries to list 
/sys/devices/virtual/net//brif/ - which is no longer populated by 
openvswitch. 

And I just tested it with 4.2 - it does exactly the same. 

Dinu


On Aug 2, 2013, at 5:15 AM, Ahmad Emneina  wrote:

> I can only guess this to be a bug. I'd file that and probably raise it to 
> critical since this seems to bet key functionality broken. Have you tried 
> this with Cloudstack 4.2 that's nearing release, and you might be able to get 
> it fixed there.
> 
> Ahmad
> 
> On Jul 23, 2013, at 10:07 AM, Dinu Arateanu  wrote:
> 
>> Hello,
>> 
>> I've been testing Cloudstack 4.1 with KVM/Openvswitch networking. When 
>> trying to add a VPC, the VR's public interface default route was not 
>> assigned correctly, nor the source nat. Cloudstack reports the VPC is 
>> created successfully, however the VR is left in an "incomplete" state. 
>> Looking through the agent logs I found: 
>> 
>> 2013-07-19 16:39:20,961 DEBUG [cloud.agent.Agent] 
>> (agentRequest-Handler-2:null) Processing command: 
>> com.cloud.agent.api.PlugNicCommand
>> 2013-07-19 16:39:20,970 DEBUG [kvm.resource.OvsVifDriver] 
>> (agentRequest-Handler-2:null) plugging 
>> nic=[Nic:Public-192.168.1.68-vlan://32]
>> 2013-07-19 16:39:20,970 DEBUG [kvm.resource.OvsVifDriver] 
>> (agentRequest-Handler-2:null) creating a vlan dev and bridge for public 
>> traffic per traffic label vswitch0
>> 2013-07-19 16:39:21,116 DEBUG [cloud.agent.Agent] 
>> (agentRequest-Handler-2:null) Processing command: 
>> com.cloud.agent.api.routing.IpAssocVpcCommand
>> 2013-07-19 16:39:21,126 DEBUG 
>> [resource.virtualnetwork.VirtualRoutingResource] 
>> (agentRequest-Handler-2:null) Executing: 
>> /usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh 
>> vpc_ipassoc.sh 169.254.2.23  -A  -l 192.168.1.68 -c ethnull -g 192.168.1.1 
>> -m 24 -n 192.168.1.0
>> 2013-07-19 16:39:29,107 DEBUG [kvm.resource.LibvirtComputingResource] 
>> (UgentTask-5:null) Executing: 
>> /usr/share/cloudstack-common/scripts/vm/network/security_group.py 
>> get_rule_logs_for_vms
>> 2013-07-19 16:39:29,233 DEBUG [kvm.resource.LibvirtComputingResource] 
>> (UgentTask-5:null) Execution is successful.
>> 2013-07-19 16:39:29,235 DEBUG [cloud.agent.Agent] (UgentTask-5:null) Sending 
>> ping: Seq 7-103:  { Cmd , MgmtId: -1, via: 7, Ver: v1, Flags: 11, 
>> [{"PingRoutingWithNwGroupsCommand":{"newGroupStates":{},"newStates":{},"_gatewayAccessible":true,"_vnetAccessible":true,"hostType":"Routing","hostId":7,"wait":0}}]
>>  }
>> 2013-07-19 16:39:29,243 DEBUG [cloud.agent.Agent] (Agent-Handler-5:null) 
>> Received response: Seq 7-103:  { Ans: , MgmtId: 112938636298, via: 7, Ver: 
>> v1, Flags: 100010, 
>> [{"PingAnswer":{"_command":{"hostType":"Routing","hostId":7,"wait":0},"result":true,"wait":0}}]
>>  }
>> 2013-07-19 16:39:38,707 DEBUG 
>> [resource.virtualnetwork.VirtualRoutingResource] 
>> (agentRequest-Handler-2:null) Execution is successful.
>> 2013-07-19 16:39:38,708 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-07-19 16:39:38,709 DEBUG [cloud.agent.Agent] 
>> (agentRequest-Handler-2:null) Processing command: 
>> com.cloud.agent.api.routing.SetSourceNatCommand
>> 2013-07-19 16:39:38,719 DEBUG [kvm.resource.LibvirtComputingResource] 
>> (agentRequest-Handler-2:null) failing to get physical interface from 
>> bridgecloud0, did not find an eth*, bond*, or vlan* in 
>> /sys/devices/virtual/net/cloud0/brif
>> 2013-07-19 16:39:38,719 DEBUG [kvm.resource.LibvirtComputingResource] 
>> (agentRequest-Handler-2:null) failed to get vlan id from bridge 
>> cloud0attached to physical interface
>> 2013-07-19 16:39:38,719 DEBUG [kvm.resource.LibvirtComputingResource] 
>> (agentRequest-Handler-2:null) failing to get physical interface from 
>> bridgevswitch0, did not find an eth*, bond*, or vlan* in 
>> /sys/devices/virtual/net/vswitch0/brif
>> 2013-07-19 16:39:38,719 DEBUG [kvm.resource.LibvirtComputingResource] 
>> (agentRequest-Handler-2:null) failed to get vlan id from bridge 
>> vswitch0attached to physical interface
>> 2013-07-19 16:39:38,719 DEBUG 
>> [resource.virtualnetwork.VirtualRoutingResource] 
>> (agentRequest-Handler-2:null) Executing: 
>> /usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh 
>> vpc_snat.sh 169.254.2.23  -A  -l 192.168.1.68 -c eth2
>> 2013-07-19 16:39:38,947 DEBUG 
>> [resource.virtualnetwork.VirtualRoutingResource] 
>> (agentRequest-Handler-2:null) Execution is successful.
>> 2013-07-19 16:39:38,948 DEBUG