cloudstack-users mailing list archives

Site index · List index
Message view « Date » · « Thread »
Top « Date » · « Thread »
From Syahrul Sazli Shaharir <sa...@pulasan.my>
Subject Re: Router VM: patchviasocket.py timeout issue on 1 out of 4 networks
Date Tue, 20 Dec 2016 02:09:56 GMT
On Mon, Dec 19, 2016 at 8:54 PM, Simon Weller <sweller@ena.com> wrote:
> When you're in the console, can you ping the host ip?

Yes - some (not all) of the IPs assigned on the host.

> What are your ip tables rules on this host currently?

Chain INPUT (policy ACCEPT)
target     prot opt source               destination
ACCEPT     udp  --  0.0.0.0/0            0.0.0.0/0            udp dpt:53
ACCEPT     tcp  --  0.0.0.0/0            0.0.0.0/0            tcp dpt:53
ACCEPT     udp  --  0.0.0.0/0            0.0.0.0/0            udp dpt:67
ACCEPT     tcp  --  0.0.0.0/0            0.0.0.0/0            tcp dpt:67

Chain FORWARD (policy ACCEPT)
target     prot opt source               destination
ACCEPT     all  --  0.0.0.0/0            192.168.122.0/24     ctstate
RELATED,ESTABLISHED
ACCEPT     all  --  192.168.122.0/24     0.0.0.0/0
ACCEPT     all  --  0.0.0.0/0            0.0.0.0/0
REJECT     all  --  0.0.0.0/0            0.0.0.0/0
reject-with icmp-port-unreachable
REJECT     all  --  0.0.0.0/0            0.0.0.0/0
reject-with icmp-port-unreachable

Chain OUTPUT (policy ACCEPT)
target     prot opt source               destination
ACCEPT     udp  --  0.0.0.0/0            0.0.0.0/0            udp dpt:68

> Can you dump the routing table as well?

Kernel IP routing table
Destination     Gateway         Genmask         Flags   MSS Window  irtt Iface
0.0.0.0         172.16.30.33      0.0.0.0         UG        0 0
  0 cloudbr2.304
10.1.30.0       0.0.0.0         255.255.255.0   U         0 0          0 bond1
10.2.30.0       0.0.0.0         255.255.255.0   U         0 0
0 cloudbr2.352
10.3.30.0       0.0.0.0         255.255.255.0   U         0 0
0 cloudbr2.353
172.16.30.32      0.0.0.0         255.255.255.224 U         0 0
  0 cloudbr2.304
169.254.0.0     0.0.0.0         255.255.0.0     U         0 0          0 cloud0
192.168.122.0   0.0.0.0         255.255.255.0   U         0 0          0 virbr0

> Have you tried a restart of one of the working networks to see if it fails on restart?

Yes, and able to restart OK. I logged on to each network's router VM
console during the patchviasocket.py stage onwards, and find the
following difference (both VMs were created and booted in the same
host):-

1. Working network router VM ( http://pastebin.com/Y6zpDa6M ) :-
.....

Dec 20 01:37:55 r-686-VM cloud: Boot up process done
Dec 20 01:37:55 r-686-VM cloud: VR config: configuation format version 1.0
Dec 20 01:37:55 r-686-VM cloud: VR config: creating file:
/var/cache/cloud/monitor_service.json
Dec 20 01:37:55 r-686-VM cloud: VR config: create file success
Dec 20 01:37:55 r-686-VM cloud: VR config: executing:
/opt/cloud/bin/update_config.py monitor_service.json
Dec 20 01:38:16 r-686-VM cloud: VR config: execution success
Dec 20 01:38:16 r-686-VM cloud: VR config: creating file:
/var/cache/cloud/vm_dhcp_entry.json
Dec 20 01:38:16 r-686-VM cloud: VR config: create file success
Dec 20 01:38:16 r-686-VM cloud: VR config: executing:
/opt/cloud/bin/update_config.py vm_dhcp_entry.json
Dec 20 01:38:38 r-686-VM cloud: VR config: execution success
Dec 20 01:38:38 r-686-VM cloud: VR config: creating file:
/var/cache/cloud/vm_dhcp_entry.json
Dec 20 01:38:38 r-686-VM cloud: VR config: create file success
Dec 20 01:38:38 r-686-VM cloud: VR config: executing:
/opt/cloud/bin/update_config.py vm_dhcp_entry.json
Dec 20 01:39:01 r-686-VM cloud: VR config: execution success
Dec 20 01:39:01 r-686-VM cloud: VR config: creating file:
/var/cache/cloud/vm_metadata.json
Dec 20 01:39:01 r-686-VM cloud: VR config: create file success
Dec 20 01:39:01 r-686-VM cloud: VR config: executing:
/opt/cloud/bin/update_config.py vm_metadata.json
Dec 20 01:39:21 r-686-VM cloud: VR config: execution success
Dec 20 01:39:21 r-686-VM cloud: VR config: creating file:
/var/cache/cloud/vm_metadata.json
Dec 20 01:39:21 r-686-VM cloud: VR config: create file success
Dec 20 01:39:21 r-686-VM cloud: VR config: executing:
/opt/cloud/bin/update_config.py vm_metadata.json
Dec 20 01:39:41 r-686-VM cloud: VR config: execution success
Dec 20 01:39:41 r-686-VM cloud: VR config: Flushing conntrack table
Dec 20 01:39:41 r-686-VM cloud: VR config: Flushing conntrack table completed
Dec 20 01:39:42 r-686-VM cloud: VR config: configuation format version 1.0
Dec 20 01:39:42 r-686-VM cloud: VR config: Flushing conntrack table
Dec 20 01:39:42 r-686-VM cloud: VR config: Flushing conntrack table completed

2. Non-working network router VM ( http://pastebin.com/jzfGMGQB ):-
.....

Dec 20 01:44:21 r-687-VM cloud: Boot up process done
Dec 20 01:44:22 r-687-VM cloud: VR config: configuation format version 1.0
Dec 20 01:44:22 r-687-VM cloud: VR config: creating file:
/var/cache/cloud/monitor_service.json
Dec 20 01:44:22 r-687-VM cloud: VR config: create file success
Dec 20 01:44:22 r-687-VM cloud: VR config: executing:
/opt/cloud/bin/update_config.py monitor_service.json
Dec 20 01:44:42 r-687-VM cloud: VR config: execution success
Dec 20 01:44:42 r-687-VM cloud: VR config: creating file:
/var/cache/cloud/vm_dhcp_entry.json
Dec 20 01:44:42 r-687-VM cloud: VR config: create file success
Dec 20 01:44:42 r-687-VM cloud: VR config: executing:
/opt/cloud/bin/update_config.py vm_dhcp_entry.json
Dec 20 01:45:05 r-687-VM cloud: VR config: execution success
Dec 20 01:45:05 r-687-VM cloud: VR config: creating file:
/var/cache/cloud/vm_dhcp_entry.json
Dec 20 01:45:05 r-687-VM cloud: VR config: create file success
Dec 20 01:45:05 r-687-VM cloud: VR config: executing:
/opt/cloud/bin/update_config.py vm_dhcp_entry.json
Dec 20 01:45:27 r-687-VM cloud: VR config: execution success
Dec 20 01:45:27 r-687-VM cloud: VR config: creating file:
/var/cache/cloud/vm_dhcp_entry.json
Dec 20 01:45:27 r-687-VM cloud: VR config: create file success
Dec 20 01:45:27 r-687-VM cloud: VR config: executing:
/opt/cloud/bin/update_config.py vm_dhcp_entry.json
Dec 20 01:45:49 r-687-VM cloud: VR config: execution success
Dec 20 01:45:49 r-687-VM cloud: VR config: creating file:
/var/cache/cloud/vm_dhcp_entry.json
Dec 20 01:45:49 r-687-VM cloud: VR config: create file success
Dec 20 01:45:49 r-687-VM cloud: VR config: executing:
/opt/cloud/bin/update_config.py vm_dhcp_entry.json
Dec 20 01:46:12 r-687-VM cloud: VR config: execution success
Dec 20 01:46:12 r-687-VM cloud: VR config: creating file:
/var/cache/cloud/vm_dhcp_entry.json
Dec 20 01:46:12 r-687-VM cloud: VR config: create file success
Dec 20 01:46:12 r-687-VM cloud: VR config: executing:
/opt/cloud/bin/update_config.py vm_dhcp_entry.json
Dec 20 01:46:22 r-687-VM shutdown[3919]: shutting down for system halt

Broadcast message from root@r-687-VM (Tue Dec 20 01:46:22 2016):

The system is going down for system halt NOW!
Dec 20 01:46:22 r-687-VM shutdown[3962]: shutting down for system halt

Broadcast message from root@r-687-VM (Tue Dec 20 01:46:22 2016):

Power button pressed
The system is going down for system halt NOW!
Dec 20 01:46:23 r-687-VM KVP: KVP starting; pid is:4037
Dec 20 01:46:23 r-687-VM cloud: VR config: executing failed:
/opt/cloud/bin/update_config.py vm_dhcp_entry.json
debug1: channel 0: free: client-session, nchannels 1
Connection to 169.254.0.197 closed by remote host.
Connection to 169.254.0.197 closed.
Transferred: sent 4336, received 93744 bytes, in 180.3 seconds
Bytes per second: sent 24.0, received 519.8
debug1: Exit status -1

Looks like the config script didn't get past vm_dhcp_entry.json ?

Thanks.

>
>
>
> ________________________________
> From: Syahrul Sazli Shaharir <sazli@pulasan.my>
> Sent: Monday, December 19, 2016 2:09 AM
> To: users@cloudstack.apache.org
> Subject: Re: Router VM: patchviasocket.py timeout issue on 1 out of 4 networks
>
> On Tue, Dec 13, 2016 at 7:26 PM, Syahrul Sazli Shaharir
> <sazli@pulasan.my> wrote:
>> Hi Simon,
>>
>> On Tue, Dec 13, 2016 at 10:31 AM, Simon Weller <sweller@ena.com> wrote:
>>> Can you turn on agent debug mode and take a look at the debug level logs?
>>>
>>>
>>> You can do that by running sed -i 's/INFO/DEBUG/g' /etc/cloudstack/agent/log4j-cloud.xml
on the host and then restarting the agent.
>>
>> Here are the debug logs - patchviasocket.py executed OK but couldn't
>> connect to the router VM's internal IP:-
>>
>> 2016-12-13 19:23:18,627 DEBUG [kvm.resource.LibvirtComputingResource]
>> (agentRequest-Handler-4:null) (logid:0bf9a356) Executing:
>> /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/patchviasocket.py
>> -n r-669-VM -p %template=domP%name=r-669-VM%eth0ip=10.3.28.10%eth0mask=255.255.255.0%gateway=10.3.28.1%domain=nocser.net%cidrsize=24%dhcprange=10.3.28.1%eth1ip=169.254.3.7%eth1mask=255.255.0.0%type=dhcpsrvr%disable_rp_filter=true%dns1=8.8.8.8%dns2=8.8.4.4%ip6dns1=%ip6dns2=%baremetalnotificationsecuritykey=uavJByNGGjNLrELG-qbdN99__1I3tnp8qa0KbcsKokKJcPB43K9s6oQu2nMLqo3YP8p6jqDy5XT3WWOWBA2yNw%baremetalnotificationapikey=8JH4mdkxsEMhgIBgMonkNXAEKjVOeZnG1m5UVekvvo4v_iXQ4ZS7rh6NNS0qphhc7ZrCauiz23tp2-Wa3AASlg%host=10.2.30.11%port=8080
>> 2016-12-13 19:23:18,739 DEBUG [kvm.resource.LibvirtComputingResource]
>> (agentRequest-Handler-4:null) (logid:0bf9a356) Execution is
>> successful.
>> 2016-12-13 19:23:18,742 DEBUG
>> [resource.virtualnetwork.VirtualRoutingResource]
>> (agentRequest-Handler-4:null) (logid:0bf9a356) Trying to connect to
>> 169.254.3.7
>> 2016-12-13 19:23:21,749 DEBUG
>> [resource.virtualnetwork.VirtualRoutingResource]
>> (agentRequest-Handler-4:null) (logid:0bf9a356) Could not connect to
>> 169.254.3.7
>> 2016-12-13 19:23:26,750 DEBUG
>> [resource.virtualnetwork.VirtualRoutingResource]
>> (agentRequest-Handler-4:null) (logid:0bf9a356) Trying to connect to
>> 169.254.3.7
>> 2016-12-13 19:23:29,757 DEBUG
>> [resource.virtualnetwork.VirtualRoutingResource]
>> (agentRequest-Handler-4:null) (logid:0bf9a356) Could not connect to
>> 169.254.3.7
>> 2016-12-13 19:23:29,869 DEBUG [cloud.agent.Agent]
>> (agentRequest-Handler-5:null) (logid:981a5f6f) Processing command:
>> com.cloud.agent.api.GetHostStatsCommand
>> 2016-12-13 19:23:34,759 DEBUG
>> [resource.virtualnetwork.VirtualRoutingResource]
>> (agentRequest-Handler-4:null) (logid:0bf9a356) Unable to logon to
>> 169.254.3.7
>>
>> virsh console also failed to show anything.
>
> Ok after upgrading to latest qemu-kvm-ev-2.6.0-27.1.el7, this time I
> got to the console at some stage, but patchviasocket.py still times
> out. Here are the console output:-
>
> http://pastebin.com/n37aHeSa
> [http://pastebin.com/i/facebook.png]<http://pastebin.com/n37aHeSa>
>
> Router VM's short lifetime - Pastebin.com<http://pastebin.com/n37aHeSa>
> pastebin.com
>
>
>
>
> Thanks.
>
>
>>> ________________________________
>>> From: Syahrul Sazli Shaharir <sazli@pulasan.my>
>>> Sent: Monday, December 12, 2016 8:21 PM
>>> To: users@cloudstack.apache.org
>>> Subject: Router VM: patchviasocket.py timeout issue on 1 out of 4 networks
>>>
>>> Hi,
>>>
>>> I am running latest Cloudstack 4.9.0.1 on CentOS 7 KVM + ceph
>>> environment. After running for some time, I faced with an issue with
>>> one out of 4 networks - following a heartbeat-induced reset on all
>>> hosts, the associated virtual router would not get recreated and
>>> started properly on any of the 3 hosts I have, even after repeated
>>> attempts of the following:-
>>> - destroy-recreate cycles, via Cloudstack UI
>>> - restartNetwork cleanup=true API calls (failed with errorcode = 530).
>>> - redownload and reregister system VM template as another entry and
>>> assign to router VM in global setting (boots the new template OK, but
>>> still same problem)
>>> - tweak default system offering for router VM (increased RAM from 256 to 512MB)
>>> - created new system offering, with RAM tweak, and use of ceph rbd
>>> store, and assigned it to Cloud.Com-SoftwareRouter as per docs - which
>>> didnt work for some reason: it kept on using initial default offering
>>> and created image on local host storage
>>> - upgrade to latest cloudstack (previously was running 4.8)
>>>
>>> As with a handful of others in this list archives, virsh list and
>>> dumpxml shows the VM created OK but failed soon after booting, as
>>> found in the following error in agent.log :-
>>>
>>> 2016-12-13 10:03:33,894 WARN  [kvm.resource.LibvirtComputingResource]
>>> (agentRequest-Handler-1:null) (logid:633e6e03) Timed out:
>>> /usr/share/cloudstack-common/scripts/vm/hypervisor/kvm/patchviasocket.py
>>> -n r-668-VM -p %template=domP%name=r-668-VM%eth0ip=10.3.28.10%eth0mask=255.255.255.0%gateway=10.3.28.1%domain=nocser.net%cidrsize=24%dhcprange=10.3.28.1%eth1ip=169.254.0.33%eth1mask=255.255.0.0%type=dhcpsrvr%disable_rp_filter=true%dns1=8.8.8.8%dns2=8.8.4.4%ip6dns1=%ip6dns2=%baremetalnotificationsecuritykey=uavJByNGGjNLrELG-qbdN99__1I3tnp8qa0KbcsKokKJcPB43K9s6oQu2nMLqo3YP8p6jqDy5XT3WWOWBA2yNw%baremetalnotificationapikey=8JH4mdkxsEMhgIBgMonkNXAEKjVOeZnG1m5UVekvvo4v_iXQ4ZS7rh6NNS0qphhc7ZrCauiz23tp2-Wa3AASlg%host=10.2.30.11%port=8080
>>> .  Output is:
>>> .....
>>> 2016-12-13 10:05:45,895 WARN  [kvm.resource.LibvirtComputingResource]
>>> (agentRequest-Handler-1:null) (logid:633e6e03) Timed out:
>>> /usr/share/cloudstack-common/scripts/network/domr/router_proxy.sh
>>> vr_cfg.sh 169.254.0.33 -c
>>> /var/cache/cloud/VR-48ea8a95-6c02-499f-88d3-eae5bf9f9fbe.cfg .  Output
>>> is:
>>>
>>> As mentioned, this only happens with 1 network (always the same
>>> network). The other router VMs work OK. Any clues on how to
>>> troubleshoot this further, would be greatly appreciated.
>>>
>>> Thanks.
>>>
>>> --
>>> --sazli



-- 
--sazli

Mime
View raw message