[cloudstack-users:0411] Re: 【質問】システムVM2台の作成、起動について（CentOS6.6+KVM+ver4.1.1）
永喜多
n ＠ gakita.me
2015年 1月 9日 (金) 11:48:58 JST
中谷さん
検証までして頂き、ありがとうございます。
永喜多です。
再度OS再インストールからセットアップをしなおました。
また、ご指摘の箇所について、確認の上設定致しました。
(1)ローカルストレージ利用時の注意点
「CloudStackを使用したことがあるので、このガイドをスキップする。」
↓
Local Storage Enabled
こちら、チェックをしていなかったため、チェックをして実行いたしました。
すると、WebUI上のインストーラの動きでは、問題なく終了しております。
※プライマリ、セカンダリストレージ共にNFSとなります
グローバル設定の、system.vm.use.local.storageはtrueにし、サーバ毎再起動しております。
(2)management-serverのIPアドレス設定の確認
propertiesの設定状況は、特に問題が見受けられない印象がありました。
[root ＠ localhost ~]# cat /etc/cloudstack/management/db.properties | grep
cluster.node.IP=
cluster.node.IP=192.168.0.10
[root ＠ localhost ~]# cat /etc/cloudstack/management/db.properties | grep
cloud.host
db.cloud.host=localhost
(3)仮想スイッチ名の確認
確認したところ、デフォルトゲートウェイになっておりましたので、変更致しました。
WebUIログイン後、【インフラストラクチャ】>【該当のゾーン】>【Physical Network】タブ>
【Physical Network 1】を押下>ゲスト&管理の、【構成】>【詳細】から、【KVMトラフィックのラベル】
を「デフォルトゲートウェイを使用」から、cloudbr0に変更致しました。
(4)その他
secstorage.allowed.internal.sitesに設定はしておりませんでしたので、10.0.0.0/24を設定致しました。
ほか、ifconfigで、自分では用途がわからないcloud0が見えております。
[root ＠ localhost ~]# ifconfig
cloud0 Link encap:Ethernet HWaddr 06:D2:8C:26:6D:D7
inet addr:169.254.0.1 Bcast:169.254.255.255 Mask:255.255.0.0
inet6 addr: fe80::4d2:8cff:fe26:6dd7/64 Scope:Link
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:0 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:0 (0.0 b) TX bytes:468 (468.0 b)
cloudbr0 Link encap:Ethernet HWaddr 00:19:99:B8:C7:51
inet addr:192.168.0.10 Bcast:192.168.0.255 Mask:255.255.255.0
inet6 addr: 240f:3:50fb:1:219:99ff:feb8:c751/64 Scope:Global
inet6 addr: fe80::219:99ff:feb8:c751/64 Scope:Link
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:2232 errors:0 dropped:0 overruns:0 frame:0
TX packets:2578 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:0
RX bytes:460822 (450.0 KiB) TX bytes:4766553 (4.5 MiB)
eth0 Link encap:Ethernet HWaddr 00:19:99:B8:C7:51
inet6 addr: fe80::219:99ff:feb8:c751/64 Scope:Link
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:3961 errors:0 dropped:0 overruns:0 frame:0
TX packets:4469 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:1088806 (1.0 MiB) TX bytes:4892195 (4.6 MiB)
Memory:ff180000-ff1fffff
eth1 Link encap:Ethernet HWaddr 00:19:99:B8:C7:52
UP BROADCAST MULTICAST MTU:1500 Metric:1
RX packets:0 errors:0 dropped:0 overruns:0 frame:0
TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:0 (0.0 b) TX bytes:0 (0.0 b)
Memory:ff100000-ff17ffff
eth2 Link encap:Ethernet HWaddr 00:19:99:B8:C7:53
UP BROADCAST MULTICAST MTU:1500 Metric:1
RX packets:0 errors:0 dropped:0 overruns:0 frame:0
TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:0 (0.0 b) TX bytes:0 (0.0 b)
Memory:ff080000-ff0fffff
eth3 Link encap:Ethernet HWaddr 00:19:99:B8:C7:54
UP BROADCAST MULTICAST MTU:1500 Metric:1
RX packets:0 errors:0 dropped:0 overruns:0 frame:0
TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:0 (0.0 b) TX bytes:0 (0.0 b)
Memory:ff000000-ff07ffff
eth4 Link encap:Ethernet HWaddr 00:50:43:00:82:1D
UP BROADCAST MULTICAST MTU:1500 Metric:1
RX packets:0 errors:0 dropped:0 overruns:0 frame:0
TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:0 (0.0 b) TX bytes:0 (0.0 b)
Interrupt:17
eth5 Link encap:Ethernet HWaddr 00:19:99:C8:77:FE
UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
RX packets:0 errors:0 dropped:0 overruns:0 frame:0
TX packets:0 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:0 (0.0 b) TX bytes:0 (0.0 b)
Interrupt:18
lo Link encap:Local Loopback
inet addr:127.0.0.1 Mask:255.0.0.0
inet6 addr: ::1/128 Scope:Host
UP LOOPBACK RUNNING MTU:65536 Metric:1
RX packets:470938 errors:0 dropped:0 overruns:0 frame:0
TX packets:470938 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:0
RX bytes:111338942 (106.1 MiB) TX bytes:111338942 (106.1 MiB)
[root ＠ localhost ~]# netstat -rn
Kernel IP routing table
Destination Gateway Genmask Flags MSS Window irtt Iface
192.168.0.0 0.0.0.0 255.255.255.0 U 0 0 0 cloudbr0
169.254.0.0 0.0.0.0 255.255.0.0 U 0 0 0 cloud0
0.0.0.0 192.168.0.1 0.0.0.0 UG 0 0 0 cloudbr0
マウント状況は以下の通りです。
[root ＠ localhost ~]# df -kh
Filesystem Size Used Avail Use% Mounted on
/dev/mapper/VolGroup-lv_root
50G 4.9G 42G 11% /
tmpfs 7.7G 80K 7.7G 1% /dev/shm
/dev/sda1 477M 36M 416M 8% /boot
/dev/mapper/VolGroup-lv_home
977G 101M 928G 1% /home
ログをtailしたところ、以下の3行のメッセージが継続して出ておりました。
2015-01-09 09:41:36,137 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 09:41:37,650 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:3,
nodeIP:192.168.0.10
2015-01-09 09:41:37,650 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
こちらが出る前に、以下のメッセージが表示されておりましたので、
db.propertiesにあるnodeのIPを変更致しました。
Detected management node left, id:1, nodeIP:169.254.0.1
変更したファイルと場所
[root ＠ localhost ~]# cat /etc/cloudstack/management/db.properties | grep
node.IP
# management server clustering parameters, change cluster.node.IP to the
machine IP address
cluster.node.IP=192.168.0.10
結果、表示されるログのIPは192.168.0.10と変わりましたが、継続して出ております。
また、例外エラーがmanagement-server.log上で一気に表示されることを確認しました。
下記の通り、Unable to contact resource.とありましたので、ホストの強制再接続を
試しておりますが、再びログに表示される次第となっております。
[root ＠ localhost ~]# tail -f
/var/log/cloudstack/management/management-server.log
2015-01-09 11:07:54,151 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 11:07:55,650 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:3,
nodeIP:192.168.0.10
2015-01-09 11:07:55,650 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
2015-01-09 11:07:55,651 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 11:07:57,150 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:3,
nodeIP:192.168.0.10
2015-01-09 11:07:57,150 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
2015-01-09 11:07:57,150 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 11:07:58,650 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:3,
nodeIP:192.168.0.10
2015-01-09 11:07:58,650 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
2015-01-09 11:07:58,650 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 11:08:00,149 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:3,
nodeIP:192.168.0.10
2015-01-09 11:08:00,149 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
2015-01-09 11:08:00,150 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 11:08:01,637 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:3,
nodeIP:192.168.0.10
2015-01-09 11:08:01,637 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
2015-01-09 11:08:01,637 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 11:08:03,149 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:3,
nodeIP:192.168.0.10
2015-01-09 11:08:03,150 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
2015-01-09 11:08:03,150 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 11:08:04,637 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:3,
nodeIP:192.168.0.10
2015-01-09 11:08:04,637 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
2015-01-09 11:08:04,637 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 11:08:06,137 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:3,
nodeIP:192.168.0.10
2015-01-09 11:08:06,137 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
2015-01-09 11:08:06,137 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 11:08:07,649 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:3,
nodeIP:192.168.0.10
2015-01-09 11:08:07,649 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
2015-01-09 11:08:07,650 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 11:08:09,150 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:3,
nodeIP:192.168.0.10
2015-01-09 11:08:09,150 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
2015-01-09 11:08:09,150 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 11:08:10,649 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:3,
nodeIP:192.168.0.10
2015-01-09 11:08:10,649 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
2015-01-09 11:08:10,650 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 11:08:12,137 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:3,
nodeIP:192.168.0.10
2015-01-09 11:08:12,137 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
2015-01-09 11:08:12,137 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 11:08:13,650 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:3,
nodeIP:192.168.0.10
2015-01-09 11:08:13,650 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
2015-01-09 11:08:13,651 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 11:08:15,150 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:3,
nodeIP:192.168.0.10
2015-01-09 11:08:15,150 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
2015-01-09 11:08:15,150 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 11:08:16,637 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:3,
nodeIP:192.168.0.10
2015-01-09 11:08:16,637 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
2015-01-09 11:08:16,637 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 11:08:17,219 DEBUG
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Zone 1
is ready to launch secondary storage VM
2015-01-09 11:08:17,225 INFO
[cloud.secstorage.PremiumSecondaryStorageManagerImpl] (secstorage-1:null)
No running secondary storage vms found in datacenter id=1, starting one
2015-01-09 11:08:17,237 INFO
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Found a
stopped secondary storage vm, bring it up to running pool. secStorageVm vm
id : 152
2015-01-09 11:08:17,252 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) VM state transitted from :Stopped to Starting with
event: StartRequestedvm's original host id: null new host id: null host id
before state transition: null
2015-01-09 11:08:17,253 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Successfully transitioned to start state for
VM[SecondaryStorageVm|s-152-VM] reservation id =
b2a1eb1c-d8a9-4058-b720-02c178b1d7f8
2015-01-09 11:08:17,266 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Trying to deploy VM, vm has dcId: 1 and podId: 1
2015-01-09 11:08:17,267 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Deploy avoids pods: null, clusters: null, hosts: null
2015-01-09 11:08:17,270 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) DeploymentPlanner allocation algorithm: random
2015-01-09 11:08:17,270 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Trying to allocate a host and storage pools from dc:1,
pod:1,cluster:null, requested cpu: 500, requested ram: 268435456
2015-01-09 11:08:17,270 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Is ROOT volume READY (pool already allocated)?: No
2015-01-09 11:08:17,271 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Searching resources only under specified Pod: 1
2015-01-09 11:08:17,272 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Listing clusters in order of aggregate capacity, that
have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2015-01-09 11:08:17,274 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) CPUOverprovisioningFactor considered: 1.0
2015-01-09 11:08:17,287 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Checking resources in Cluster: 1 under Pod: 1
2015-01-09 11:08:17,287 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1
cluster:1
2015-01-09 11:08:17,290 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to
check for allocation: [Host[-1-Routing]]
2015-01-09 11:08:17,295 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Found 1 hosts for allocation after
prioritization: [Host[-1-Routing]]
2015-01-09 11:08:17,295 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=256
2015-01-09 11:08:17,298 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:FirstFitRoutingAllocator) Checking if host: 1 has enough
capacity for requested CPU: 500 and requested RAM: 268435456 ,
cpuOverprovisioningFactor: 1.0
2015-01-09 11:08:17,303 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:FirstFitRoutingAllocator) Hosts's actual total CPU: 19200 and
CPU after applying overprovisioning: 19200
2015-01-09 11:08:17,304 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:FirstFitRoutingAllocator) Free CPU: 19200 , Requested CPU:
500
2015-01-09 11:08:17,304 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:FirstFitRoutingAllocator) Free RAM: 16420503552 , Requested
RAM: 268435456
2015-01-09 11:08:17,304 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:FirstFitRoutingAllocator) Host has enough CPU and RAM
available
2015-01-09 11:08:17,304 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:FirstFitRoutingAllocator) STATS: Can alloc CPU from host: 1,
used: 0, reserved: 0, actual total: 19200, total with overprovisioning:
19200; requested cpu:500,alloc_from_last_host?:false
,considerReservedCapacity?: true
2015-01-09 11:08:17,304 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:FirstFitRoutingAllocator) STATS: Can alloc MEM from host: 1,
used: 0, reserved: 0, total: 16420503552; requested mem:
268435456,alloc_from_last_host?:false ,considerReservedCapacity?: true
2015-01-09 11:08:17,304 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Found a suitable host, adding to
list: 1
2015-01-09 11:08:17,304 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Host Allocator returning 1 suitable
hosts
2015-01-09 11:08:17,307 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Checking suitable pools for volume (Id, Type):
(152,ROOT)
2015-01-09 11:08:17,308 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) We need to allocate new storagepool for this volume
2015-01-09 11:08:17,308 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Calling StoragePoolAllocators to find suitable pools
2015-01-09 11:08:17,310 DEBUG [storage.allocator.LocalStoragePoolAllocator]
(secstorage-1:null) LocalStoragePoolAllocator trying to find storage pool
to fit the vm
2015-01-09 11:08:17,310 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null)
Looking for pools in dc: 1 pod:1 cluster:1
2015-01-09 11:08:17,312 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null)
FirstFitStoragePoolAllocator has 1 pools to check for allocation
2015-01-09 11:08:17,312 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null)
Checking if storage pool is suitable, name: localhost ,poolId: 200
2015-01-09 11:08:17,313 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) Is
localStorageAllocationNeeded? true
2015-01-09 11:08:17,313 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null) Is
storage pool shared? false
2015-01-09 11:08:17,317 DEBUG [cloud.storage.StorageManagerImpl]
(secstorage-1:null) Checking pool 200 for storage, totalSize:
1048881356800, usedBytes: 105758720, usedPct: 1.008300121976198E-4, disable
threshold: 0.85
2015-01-09 11:08:17,327 DEBUG [cloud.storage.StorageManagerImpl]
(secstorage-1:null) Checking pool: 200 for volume allocation
[Vol[152|vm=152|ROOT]], maxSize : 1048881356800, totalAllocatedSize :
139264, askingSize : 0, allocated disable threshold: 0.85
2015-01-09 11:08:17,327 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null)
FirstFitStoragePoolAllocator returning 1 suitable storage pools
2015-01-09 11:08:17,329 DEBUG [storage.allocator.LocalStoragePoolAllocator]
(secstorage-1:null) Found suitable local storage pool 200, adding to list
2015-01-09 11:08:17,330 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null)
Looking for pools in dc: 1 pod:1 cluster:1
2015-01-09 11:08:17,332 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null)
FirstFitStoragePoolAllocator has 1 pools to check for allocation
2015-01-09 11:08:17,333 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null)
Checking if storage pool is suitable, name: localhost ,poolId: 200
2015-01-09 11:08:17,333 DEBUG
[storage.allocator.AbstractStoragePoolAllocator] (secstorage-1:null)
StoragePool is in avoid set, skipping this pool
2015-01-09 11:08:17,333 DEBUG
[storage.allocator.FirstFitStoragePoolAllocator] (secstorage-1:null)
FirstFitStoragePoolAllocator returning 0 suitable storage pools
2015-01-09 11:08:17,333 DEBUG [storage.allocator.LocalStoragePoolAllocator]
(secstorage-1:null) LocalStoragePoolAllocator returning 1 suitable storage
pools
2015-01-09 11:08:17,333 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Trying to find a potenial host and associated storage
pools from the suitable host/pool lists for this VM
2015-01-09 11:08:17,333 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Checking if host: 1 can access any suitable storage
pool for volume: ROOT
2015-01-09 11:08:17,335 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Host: 1 can access pool: 200
2015-01-09 11:08:17,336 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Found a potential host id: 1 name: localhost and
associated storage pools for this VM
2015-01-09 11:08:17,338 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Returning Deployment Destination:
Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))]
:
Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(152|ROOT-->Pool(200))]
2015-01-09 11:08:17,339 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Deployment found - P0=VM[SecondaryStorageVm|s-152-VM],
P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))]
:
Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage(Volume(152|ROOT-->Pool(200))]
2015-01-09 11:08:17,358 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) VM state transitted from :Starting to Starting with
event: OperationRetryvm's original host id: null new host id: 1 host id
before state transition: null
2015-01-09 11:08:17,371 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) Hosts's actual total CPU: 19200 and CPU after applying
overprovisioning: 19200
2015-01-09 11:08:17,371 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) We are allocating VM, increasing the used capacity of
this host:1
2015-01-09 11:08:17,371 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) Current Used CPU: 0 , Free CPU:19200 ,Requested CPU:
500
2015-01-09 11:08:17,371 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) Current Used RAM: 0 , Free RAM:16420503552 ,Requested
RAM: 268435456
2015-01-09 11:08:17,371 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) CPU STATS after allocation: for host: 1, old used: 0,
old reserved: 0, actual total: 19200, total with overprovisioning: 19200;
new used:500, reserved:0; requested cpu:500,alloc_from_last:false
2015-01-09 11:08:17,371 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) RAM STATS after allocation: for host: 1, old used: 0,
old reserved: 0, total: 16420503552; new used: 268435456, reserved: 0;
requested mem: 268435456,alloc_from_last:false
2015-01-09 11:08:17,383 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) VM is being created in podId: 1
2015-01-09 11:08:17,393 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Lock is acquired for network id 204 as a part of
network implement
2015-01-09 11:08:17,393 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Network id=204 is already implemented
2015-01-09 11:08:17,394 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Lock is released for network id 204 as a part of
network implement
2015-01-09 11:08:17,449 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking NiciraNvp to prepare for
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:17,449 DEBUG [network.element.NiciraNvpElement]
(secstorage-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network defaultGuestNetwork
2015-01-09 11:08:17,449 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking JuniperSRX to prepare for
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:17,449 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Netscaler to prepare for
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:17,449 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking F5BigIP to prepare for
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:17,449 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking CiscoNexus1000vVSM to prepare for
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:17,450 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking BigSwitchVnsElement to prepare for
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:17,450 DEBUG [network.element.BigSwitchVnsElement]
(secstorage-1:null) Checking if BigSwitchVnsElement can handle service
Connectivity on network defaultGuestNetwork
2015-01-09 11:08:17,450 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to prepare for
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:17,450 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Ovs to prepare for
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:17,450 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to prepare for
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:17,450 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VpcVirtualRouter to prepare for
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:17,450 WARN [network.element.VpcVirtualRouterElement]
(secstorage-1:null) Network Ntwk[204|Guest|6] is not associated with any
VPC
2015-01-09 11:08:17,460 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Lock is acquired for network id 202 as a part of
network implement
2015-01-09 11:08:17,460 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Network id=202 is already implemented
2015-01-09 11:08:17,461 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Lock is released for network id 202 as a part of
network implement
2015-01-09 11:08:17,520 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking NiciraNvp to prepare for
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
2015-01-09 11:08:17,521 DEBUG [network.element.NiciraNvpElement]
(secstorage-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network null
2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking JuniperSRX to prepare for
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Netscaler to prepare for
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking F5BigIP to prepare for
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking CiscoNexus1000vVSM to prepare for
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking BigSwitchVnsElement to prepare for
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
2015-01-09 11:08:17,521 DEBUG [network.element.BigSwitchVnsElement]
(secstorage-1:null) Checking if BigSwitchVnsElement can handle service
Connectivity on network null
2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to prepare for
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Ovs to prepare for
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to prepare for
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
2015-01-09 11:08:17,521 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VpcVirtualRouter to prepare for
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-169.254.3.179]
2015-01-09 11:08:17,522 WARN [network.element.VpcVirtualRouterElement]
(secstorage-1:null) Network Ntwk[202|Control|3] is not associated with any
VPC
2015-01-09 11:08:17,525 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Lock is acquired for network id 201 as a part of
network implement
2015-01-09 11:08:17,525 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Network id=201 is already implemented
2015-01-09 11:08:17,526 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Lock is released for network id 201 as a part of
network implement
2015-01-09 11:08:17,571 DEBUG [network.guru.PodBasedNetworkGuru]
(secstorage-1:null) Allocated a nic
NicProfile[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103-null
for VM[SecondaryStorageVm|s-152-VM]
2015-01-09 11:08:17,584 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking NiciraNvp to prepare for
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
2015-01-09 11:08:17,584 DEBUG [network.element.NiciraNvpElement]
(secstorage-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network null
2015-01-09 11:08:17,584 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking JuniperSRX to prepare for
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
2015-01-09 11:08:17,584 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Netscaler to prepare for
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
2015-01-09 11:08:17,584 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking F5BigIP to prepare for
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
2015-01-09 11:08:17,584 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking CiscoNexus1000vVSM to prepare for
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
2015-01-09 11:08:17,585 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking BigSwitchVnsElement to prepare for
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
2015-01-09 11:08:17,585 DEBUG [network.element.BigSwitchVnsElement]
(secstorage-1:null) Checking if BigSwitchVnsElement can handle service
Connectivity on network null
2015-01-09 11:08:17,585 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to prepare for
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
2015-01-09 11:08:17,585 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Ovs to prepare for
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
2015-01-09 11:08:17,585 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to prepare for
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
2015-01-09 11:08:17,585 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VpcVirtualRouter to prepare for
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.103]
2015-01-09 11:08:17,585 WARN [network.element.VpcVirtualRouterElement]
(secstorage-1:null) Network Ntwk[201|Management|2] is not associated with
any VPC
2015-01-09 11:08:17,589 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Lock is acquired for network id 203 as a part of
network implement
2015-01-09 11:08:17,589 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Network id=203 is already implemented
2015-01-09 11:08:17,590 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Lock is released for network id 203 as a part of
network implement
2015-01-09 11:08:17,637 DEBUG [network.guru.PodBasedNetworkGuru]
(secstorage-1:null) Allocated a nic
NicProfile[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108-null
for VM[SecondaryStorageVm|s-152-VM]
2015-01-09 11:08:17,649 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking NiciraNvp to prepare for
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
2015-01-09 11:08:17,649 DEBUG [network.element.NiciraNvpElement]
(secstorage-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network null
2015-01-09 11:08:17,649 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking JuniperSRX to prepare for
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
2015-01-09 11:08:17,649 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Netscaler to prepare for
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
2015-01-09 11:08:17,649 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking F5BigIP to prepare for
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
2015-01-09 11:08:17,649 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking CiscoNexus1000vVSM to prepare for
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
2015-01-09 11:08:17,650 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking BigSwitchVnsElement to prepare for
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
2015-01-09 11:08:17,650 DEBUG [network.element.BigSwitchVnsElement]
(secstorage-1:null) Checking if BigSwitchVnsElement can handle service
Connectivity on network null
2015-01-09 11:08:17,650 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to prepare for
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
2015-01-09 11:08:17,650 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Ovs to prepare for
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
2015-01-09 11:08:17,650 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to prepare for
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
2015-01-09 11:08:17,650 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VpcVirtualRouter to prepare for
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.108]
2015-01-09 11:08:17,650 WARN [network.element.VpcVirtualRouterElement]
(secstorage-1:null) Network Ntwk[203|Storage|4] is not associated with any
VPC
2015-01-09 11:08:17,653 DEBUG [cloud.storage.StorageManagerImpl]
(secstorage-1:null) Checking if we need to prepare 1 volumes for
VM[SecondaryStorageVm|s-152-VM]
2015-01-09 11:08:17,666 DEBUG [cloud.storage.StorageManagerImpl]
(secstorage-1:null) Creating volume: Vol[152|vm=152|ROOT]
2015-01-09 11:08:17,666 DEBUG [cloud.storage.StorageManagerImpl]
(secstorage-1:null) Trying to create in Pool[200|Filesystem]
2015-01-09 11:08:17,690 DEBUG [cloud.template.TemplateManagerImpl]
(secstorage-1:null) Template 3 has already been downloaded to pool 200
2015-01-09 11:08:17,700 DEBUG [agent.transport.Request] (secstorage-1:null)
Seq 1-816644129: Sending { Cmd , MgmtId: 7501364227543, via: 1, Ver: v1,
Flags: 100111,
[{"storage.CreateCommand":{"volId":152,"pool":{"id":200,"uuid":"89e750c4-79af-4ed3-bee6-53fcec68ac96","host":"192.168.0.10","path":"/var/lib/libvirt/images/","port":0,"type":"Filesystem"},"diskCharacteristics":{"size":0,"tags":[],"type":"ROOT","name":"ROOT-152","useLocalStorage":true,"recreatable":true,"diskOfferingId":9,"volumeId":152,"hyperType":"KVM"},"templateUrl":"b5740808-e1e4-4537-8d57-5c9fa4addc94","wait":0}}]
}
2015-01-09 11:08:17,745 DEBUG [agent.transport.Request]
(AgentManager-Handler-10:null) Seq 1-816644129: Processing: { Ans: ,
MgmtId: 7501364227543, via: 1, Ver: v1, Flags: 110,
[{"storage.CreateAnswer":{"requestTemplateReload":false,"result":false,"details":"Exception:
com.cloud.utils.exception.CloudRuntimeException\nMessage:
org.libvirt.LibvirtException: Storage volume not found: no storage vol with
matching name 'b5740808-e1e4-4537-8d57-5c9fa4addc94'\nStack:
com.cloud.utils.exception.CloudRuntimeException:
org.libvirt.LibvirtException: Storage volume not found: no storage vol with
matching name 'b5740808-e1e4-4537-8d57-5c9fa4addc94'\n\tat
com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getVolume(LibvirtStorageAdaptor.java:90)\n\tat
com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.getPhysicalDisk(LibvirtStorageAdaptor.java:437)\n\tat
com.cloud.hypervisor.kvm.storage.LibvirtStoragePool.getPhysicalDisk(LibvirtStoragePool.java:123)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(LibvirtComputingResource.java:1279)\n\tat
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1072)\n\tat
com.cloud.agent.Agent.processRequest(Agent.java:525)\n\tat
com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)\n\tat
com.cloud.utils.nio.Task.run(Task.java:83)\n\tat
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)\n\tat
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)\n\tat
java.lang.Thread.run(Thread.java:745)\n","wait":0}}] }
2015-01-09 11:08:17,745 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-10:null) Seq 1-816644129: No more commands found
2015-01-09 11:08:17,745 DEBUG [agent.transport.Request] (secstorage-1:null)
Seq 1-816644129: Received: { Ans: , MgmtId: 7501364227543, via: 1, Ver: v1,
Flags: 110, { CreateAnswer } }
2015-01-09 11:08:17,746 DEBUG [cloud.storage.StorageManagerImpl]
(secstorage-1:null) Unable to create volume Vol[152|vm=152|ROOT]
2015-01-09 11:08:17,758 INFO [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Unable to contact resource.
com.cloud.exception.StorageUnavailableException: Resource [StoragePool:200]
is unreachable: Unable to create Vol[152|vm=152|ROOT]
at
com.cloud.storage.StorageManagerImpl.prepare(StorageManagerImpl.java:3488)
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:748)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:471)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:464)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:269)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:696)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1307)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:121)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:52)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:104)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
at
com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-01-09 11:08:17,770 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Cleaning up resources for the vm
VM[SecondaryStorageVm|s-152-VM] in Starting state
2015-01-09 11:08:17,774 DEBUG [agent.transport.Request] (secstorage-1:null)
Seq 1-816644130: Sending { Cmd , MgmtId: 7501364227543, via: 1, Ver: v1,
Flags: 100111,
[{"StopCommand":{"isProxy":false,"vmName":"s-152-VM","wait":0}}] }
2015-01-09 11:08:17,794 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Zone 1 is ready to launch console proxy
2015-01-09 11:08:17,794 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Expand console proxy standby capacity for zone zone1
2015-01-09 11:08:17,800 INFO [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Found a stopped console proxy, bring it up to running
pool. proxy vm id : 2
2015-01-09 11:08:17,814 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) VM state transitted from :Stopped to Starting with
event: StartRequestedvm's original host id: null new host id: null host id
before state transition: null
2015-01-09 11:08:17,814 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Successfully transitioned to start state for
VM[ConsoleProxy|v-2-VM] reservation id =
09d9d4b5-2cf9-487e-aa85-cd98be5b03d9
2015-01-09 11:08:17,828 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Trying to deploy VM, vm has dcId: 1 and podId: 1
2015-01-09 11:08:17,828 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Deploy avoids pods: null, clusters: null, hosts: null
2015-01-09 11:08:17,833 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Root volume is ready, need to place VM in volume's
cluster
2015-01-09 11:08:17,833 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Vol[2|vm=2|ROOT] is READY, changing deployment plan
to use this pool's dcId: 1 , podId: 1 , and clusterId: 1
2015-01-09 11:08:17,835 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) DeploymentPlanner allocation algorithm: random
2015-01-09 11:08:17,835 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Trying to allocate a host and storage pools from
dc:1, pod:1,cluster:1, requested cpu: 500, requested ram: 1073741824
2015-01-09 11:08:17,835 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Is ROOT volume READY (pool already allocated)?: Yes
2015-01-09 11:08:17,835 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Searching resources only under specified Cluster: 1
2015-01-09 11:08:17,845 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Checking resources in Cluster: 1 under Pod: 1
2015-01-09 11:08:17,845 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1
cluster:1
2015-01-09 11:08:17,849 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to
check for allocation: [Host[-1-Routing]]
2015-01-09 11:08:17,856 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) Found 1 hosts for allocation
after prioritization: [Host[-1-Routing]]
2015-01-09 11:08:17,857 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) Looking for speed=500Mhz,
Ram=1024
2015-01-09 11:08:17,860 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:FirstFitRoutingAllocator) Checking if host: 1 has enough
capacity for requested CPU: 500 and requested RAM: 1073741824 ,
cpuOverprovisioningFactor: 1.0
2015-01-09 11:08:17,865 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:FirstFitRoutingAllocator) Hosts's actual total CPU: 19200
and CPU after applying overprovisioning: 19200
2015-01-09 11:08:17,866 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:FirstFitRoutingAllocator) Free CPU: 18700 , Requested CPU:
500
2015-01-09 11:08:17,866 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:FirstFitRoutingAllocator) Free RAM: 16152068096 , Requested
RAM: 1073741824
2015-01-09 11:08:17,866 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:FirstFitRoutingAllocator) Host has enough CPU and RAM
available
2015-01-09 11:08:17,866 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc CPU from host:
1, used: 500, reserved: 0, actual total: 19200, total with
overprovisioning: 19200; requested cpu:500,alloc_from_last_host?:false
,considerReservedCapacity?: true
2015-01-09 11:08:17,866 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:FirstFitRoutingAllocator) STATS: Can alloc MEM from host:
1, used: 268435456, reserved: 0, total: 16420503552; requested mem:
1073741824,alloc_from_last_host?:false ,considerReservedCapacity?: true
2015-01-09 11:08:17,866 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) Found a suitable host, adding to
list: 1
2015-01-09 11:08:17,866 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) Host Allocator returning 1
suitable hosts
2015-01-09 11:08:17,870 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Checking suitable pools for volume (Id, Type):
(2,ROOT)
2015-01-09 11:08:17,870 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Volume has pool(200) already allocated, checking if
pool can be reused, poolId: 200
2015-01-09 11:08:17,870 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) finding pool by id '200'
2015-01-09 11:08:17,872 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Planner need not allocate a pool for this volume
since its READY
2015-01-09 11:08:17,872 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Trying to find a potenial host and associated storage
pools from the suitable host/pool lists for this VM
2015-01-09 11:08:17,873 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Checking if host: 1 can access any suitable storage
pool for volume: ROOT
2015-01-09 11:08:17,875 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Host: 1 can access pool: 200
2015-01-09 11:08:17,875 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Found a potential host id: 1 name: localhost and
associated storage pools for this VM
2015-01-09 11:08:17,878 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Returning Deployment Destination:
Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))]
: Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage()]
2015-01-09 11:08:17,878 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Deployment found - P0=VM[ConsoleProxy|v-2-VM],
P0=Dest[Zone(Id)-Pod(Id)-Cluster(Id)-Host(Id)-Storage(Volume(Id|Type-->Pool(Id))]
: Dest[Zone(1)-Pod(1)-Cluster(1)-Host(1)-Storage()]
2015-01-09 11:08:17,897 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) VM state transitted from :Starting to Starting with
event: OperationRetryvm's original host id: null new host id: 1 host id
before state transition: null
2015-01-09 11:08:17,910 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) Hosts's actual total CPU: 19200 and CPU after
applying overprovisioning: 19200
2015-01-09 11:08:17,910 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) We are allocating VM, increasing the used capacity of
this host:1
2015-01-09 11:08:17,910 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) Current Used CPU: 500 , Free CPU:18700 ,Requested
CPU: 500
2015-01-09 11:08:17,910 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) Current Used RAM: 268435456 , Free RAM:16152068096
,Requested RAM: 1073741824
2015-01-09 11:08:17,911 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) CPU STATS after allocation: for host: 1, old used:
500, old reserved: 0, actual total: 19200, total with overprovisioning:
19200; new used:1000, reserved:0; requested cpu:500,alloc_from_last:false
2015-01-09 11:08:17,911 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) RAM STATS after allocation: for host: 1, old used:
268435456, old reserved: 0, total: 16420503552; new used: 1342177280,
reserved: 0; requested mem: 1073741824,alloc_from_last:false
2015-01-09 11:08:17,922 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) VM is being created in podId: 1
2015-01-09 11:08:17,931 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Lock is acquired for network id 204 as a part of
network implement
2015-01-09 11:08:17,931 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Network id=204 is already implemented
2015-01-09 11:08:17,932 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Lock is released for network id 204 as a part of
network implement
2015-01-09 11:08:17,985 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking NiciraNvp to prepare for
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:17,986 DEBUG [network.element.NiciraNvpElement]
(consoleproxy-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network defaultGuestNetwork
2015-01-09 11:08:17,986 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking JuniperSRX to prepare for
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:17,986 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Netscaler to prepare for
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:17,986 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking F5BigIP to prepare for
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:17,986 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking CiscoNexus1000vVSM to prepare for
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:17,986 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking BigSwitchVnsElement to prepare for
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:17,986 DEBUG [network.element.BigSwitchVnsElement]
(consoleproxy-1:null) Checking if BigSwitchVnsElement can handle service
Connectivity on network defaultGuestNetwork
2015-01-09 11:08:17,986 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VirtualRouter to prepare for
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:17,986 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Ovs to prepare for
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:17,986 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking SecurityGroupProvider to prepare for
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:17,987 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VpcVirtualRouter to prepare for
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:17,987 WARN [network.element.VpcVirtualRouterElement]
(consoleproxy-1:null) Network Ntwk[204|Guest|6] is not associated with any
VPC
2015-01-09 11:08:17,989 DEBUG [agent.transport.Request]
(AgentManager-Handler-11:null) Seq 1-816644130: Processing: { Ans: ,
MgmtId: 7501364227543, via: 1, Ver: v1, Flags: 110,
[{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
2015-01-09 11:08:17,989 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-11:null) Seq 1-816644130: No more commands found
2015-01-09 11:08:17,989 DEBUG [agent.transport.Request] (secstorage-1:null)
Seq 1-816644130: Received: { Ans: , MgmtId: 7501364227543, via: 1, Ver: v1,
Flags: 110, { StopAnswer } }
2015-01-09 11:08:17,997 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Lock is acquired for network id 202 as a part of
network implement
2015-01-09 11:08:17,997 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Network id=202 is already implemented
2015-01-09 11:08:17,998 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Lock is released for network id 202 as a part of
network implement
2015-01-09 11:08:18,019 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking NiciraNvp to release
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:18,019 DEBUG [network.element.NiciraNvpElement]
(secstorage-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network defaultGuestNetwork
2015-01-09 11:08:18,019 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking JuniperSRX to release
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:18,019 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Netscaler to release
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:18,020 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking F5BigIP to release
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:18,020 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking CiscoNexus1000vVSM to release
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:18,020 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking BigSwitchVnsElement to release
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:18,020 DEBUG [network.element.BigSwitchVnsElement]
(secstorage-1:null) Checking if BigSwitchVnsElement can handle service
Connectivity on network defaultGuestNetwork
2015-01-09 11:08:18,020 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to release
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:18,020 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Ovs to release
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:18,020 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to release
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:18,020 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VpcVirtualRouter to release
Nic[604-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-192.168.0.112]
2015-01-09 11:08:18,026 DEBUG [network.guru.ControlNetworkGuru]
(secstorage-1:null) Released nic: NicProfile[605-152-null-null-null
2015-01-09 11:08:18,036 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking NiciraNvp to release
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,036 DEBUG [network.element.NiciraNvpElement]
(secstorage-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network null
2015-01-09 11:08:18,036 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking JuniperSRX to release
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,036 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Netscaler to release
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,036 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking F5BigIP to release
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,036 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking CiscoNexus1000vVSM to release
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,036 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking BigSwitchVnsElement to release
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,037 DEBUG [network.element.BigSwitchVnsElement]
(secstorage-1:null) Checking if BigSwitchVnsElement can handle service
Connectivity on network null
2015-01-09 11:08:18,037 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to release
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,037 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Ovs to release
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,037 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to release
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,037 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VpcVirtualRouter to release
Nic[605-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,045 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
(secstorage-1:null) Releasing ip address for
reservationId=b2a1eb1c-d8a9-4058-b720-02c178b1d7f8, instance=606
2015-01-09 11:08:18,046 DEBUG [network.guru.PodBasedNetworkGuru]
(secstorage-1:null) Released nic: NicProfile[606-152-null-null-null
2015-01-09 11:08:18,058 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking NiciraNvp to release
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,058 DEBUG [network.element.NiciraNvpElement]
(secstorage-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network null
2015-01-09 11:08:18,058 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking JuniperSRX to release
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,058 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Netscaler to release
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,058 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking F5BigIP to release
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,058 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking CiscoNexus1000vVSM to release
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,059 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking BigSwitchVnsElement to release
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,059 DEBUG [network.element.BigSwitchVnsElement]
(secstorage-1:null) Checking if BigSwitchVnsElement can handle service
Connectivity on network null
2015-01-09 11:08:18,059 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to release
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,059 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Ovs to release
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,059 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to release
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,059 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VpcVirtualRouter to release
Nic[606-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,068 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking NiciraNvp to prepare for
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
2015-01-09 11:08:18,068 DEBUG [network.element.NiciraNvpElement]
(consoleproxy-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network null
2015-01-09 11:08:18,068 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking JuniperSRX to prepare for
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
2015-01-09 11:08:18,068 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Netscaler to prepare for
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
2015-01-09 11:08:18,068 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking F5BigIP to prepare for
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
2015-01-09 11:08:18,068 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking CiscoNexus1000vVSM to prepare for
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
2015-01-09 11:08:18,068 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking BigSwitchVnsElement to prepare for
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
2015-01-09 11:08:18,068 DEBUG [network.element.BigSwitchVnsElement]
(consoleproxy-1:null) Checking if BigSwitchVnsElement can handle service
Connectivity on network null
2015-01-09 11:08:18,068 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VirtualRouter to prepare for
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
2015-01-09 11:08:18,069 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Ovs to prepare for
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
2015-01-09 11:08:18,069 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking SecurityGroupProvider to prepare for
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
2015-01-09 11:08:18,069 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VpcVirtualRouter to prepare for
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-169.254.0.22]
2015-01-09 11:08:18,069 WARN [network.element.VpcVirtualRouterElement]
(consoleproxy-1:null) Network Ntwk[202|Control|3] is not associated with
any VPC
2015-01-09 11:08:18,069 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
(secstorage-1:null) Releasing ip address for
reservationId=b2a1eb1c-d8a9-4058-b720-02c178b1d7f8, instance=607
2015-01-09 11:08:18,071 DEBUG [network.guru.PodBasedNetworkGuru]
(secstorage-1:null) Released nic: NicProfile[607-152-null-null-null
2015-01-09 11:08:18,073 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Lock is acquired for network id 201 as a part of
network implement
2015-01-09 11:08:18,073 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Network id=201 is already implemented
2015-01-09 11:08:18,074 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Lock is released for network id 201 as a part of
network implement
2015-01-09 11:08:18,082 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking NiciraNvp to release
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,082 DEBUG [network.element.NiciraNvpElement]
(secstorage-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network null
2015-01-09 11:08:18,082 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking JuniperSRX to release
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,083 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Netscaler to release
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,083 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking F5BigIP to release
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,083 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking CiscoNexus1000vVSM to release
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,083 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking BigSwitchVnsElement to release
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,083 DEBUG [network.element.BigSwitchVnsElement]
(secstorage-1:null) Checking if BigSwitchVnsElement can handle service
Connectivity on network null
2015-01-09 11:08:18,083 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VirtualRouter to release
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,083 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking Ovs to release
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,083 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking SecurityGroupProvider to release
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,083 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Asking VpcVirtualRouter to release
Nic[607-152-b2a1eb1c-d8a9-4058-b720-02c178b1d7f8-null]
2015-01-09 11:08:18,084 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Successfully released network resources for the vm
VM[SecondaryStorageVm|s-152-VM]
2015-01-09 11:08:18,084 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Successfully cleanued up resources for the vm
VM[SecondaryStorageVm|s-152-VM] in Starting state
2015-01-09 11:08:18,087 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) DeploymentPlanner allocation algorithm: random
2015-01-09 11:08:18,088 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Trying to allocate a host and storage pools from dc:1,
pod:1,cluster:null, requested cpu: 500, requested ram: 268435456
2015-01-09 11:08:18,088 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Is ROOT volume READY (pool already allocated)?: No
2015-01-09 11:08:18,088 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Searching resources only under specified Pod: 1
2015-01-09 11:08:18,090 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Listing clusters in order of aggregate capacity, that
have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2015-01-09 11:08:18,091 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) CPUOverprovisioningFactor considered: 1.0
2015-01-09 11:08:18,104 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Checking resources in Cluster: 1 under Pod: 1
2015-01-09 11:08:18,104 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1
cluster:1
2015-01-09 11:08:18,108 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to
check for allocation: [Host[-1-Routing]]
2015-01-09 11:08:18,113 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Found 1 hosts for allocation after
prioritization: [Host[-1-Routing]]
2015-01-09 11:08:18,113 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Looking for speed=500Mhz, Ram=256
2015-01-09 11:08:18,113 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Host name: localhost, hostId: 1 is
in avoid set, skipping this and trying other available hosts
2015-01-09 11:08:18,113 DEBUG [allocator.impl.FirstFitAllocator]
(secstorage-1:FirstFitRoutingAllocator) Host Allocator returning 0 suitable
hosts
2015-01-09 11:08:18,113 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) No suitable hosts found
2015-01-09 11:08:18,113 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) No suitable hosts found under this Cluster: 1
2015-01-09 11:08:18,113 DEBUG [cloud.deploy.FirstFitPlanner]
(secstorage-1:null) Could not find suitable Deployment Destination for this
VM under any clusters, returning.
2015-01-09 11:08:18,120 DEBUG [network.guru.PodBasedNetworkGuru]
(consoleproxy-1:null) Allocated a nic
NicProfile[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105-null for
VM[ConsoleProxy|v-2-VM]
2015-01-09 11:08:18,139 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking NiciraNvp to prepare for
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
2015-01-09 11:08:18,140 DEBUG [network.element.NiciraNvpElement]
(consoleproxy-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network null
2015-01-09 11:08:18,140 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking JuniperSRX to prepare for
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
2015-01-09 11:08:18,140 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Netscaler to prepare for
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
2015-01-09 11:08:18,140 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking F5BigIP to prepare for
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
2015-01-09 11:08:18,140 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking CiscoNexus1000vVSM to prepare for
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
2015-01-09 11:08:18,140 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking BigSwitchVnsElement to prepare for
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
2015-01-09 11:08:18,140 DEBUG [network.element.BigSwitchVnsElement]
(consoleproxy-1:null) Checking if BigSwitchVnsElement can handle service
Connectivity on network null
2015-01-09 11:08:18,140 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VirtualRouter to prepare for
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
2015-01-09 11:08:18,141 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Ovs to prepare for
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
2015-01-09 11:08:18,141 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking SecurityGroupProvider to prepare for
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
2015-01-09 11:08:18,141 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VpcVirtualRouter to prepare for
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.105]
2015-01-09 11:08:18,141 WARN [network.element.VpcVirtualRouterElement]
(consoleproxy-1:null) Network Ntwk[201|Management|2] is not associated with
any VPC
2015-01-09 11:08:18,144 DEBUG [cloud.storage.StorageManagerImpl]
(consoleproxy-1:null) Checking if we need to prepare 1 volumes for
VM[ConsoleProxy|v-2-VM]
2015-01-09 11:08:18,145 DEBUG [cloud.storage.StorageManagerImpl]
(consoleproxy-1:null) No need to recreate the volume: Vol[2|vm=2|ROOT],
since it already has a pool assigned: 200, adding disk to VM
2015-01-09 11:08:18,151 DEBUG [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Detected management node left, id:3,
nodeIP:192.168.0.10
2015-01-09 11:08:18,151 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Trying to connect to 192.168.0.10
2015-01-09 11:08:18,152 INFO [cloud.cluster.ClusterManagerImpl]
(Cluster-Heartbeat-1:null) Management node 3 is detected inactive by
timestamp but is pingable
2015-01-09 11:08:18,153 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Boot Args for VM[ConsoleProxy|v-2-VM]: template=domP
type=consoleproxy host=192.168.0.10 port=8250 name=v-2-VM premium=true
zone=1 pod=1 guid=Proxy.2 proxy_vm=2 disable_rp_filter=true
eth2ip=192.168.0.111 eth2mask=255.255.255.0 gateway=192.168.0.1
eth0ip=169.254.0.22 eth0mask=255.255.0.0 eth1ip=192.168.0.105
eth1mask=255.255.255.0 mgmtcidr=192.168.0.0/24 localgw=192.168.0.1
internaldns1=8.8.8.8 internaldns2=8.8.4.4 dns1=8.8.8.8 dns2=8.8.4.4
2015-01-09 11:08:18,158 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) VM state transitted from :Starting to Stopped with
event: OperationFailedvm's original host id: null new host id: null host id
before state transition: 1
2015-01-09 11:08:18,169 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) Hosts's actual total CPU: 19200 and CPU after applying
overprovisioning: 19200
2015-01-09 11:08:18,169 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) release cpu from host: 1, old used: 1000,reserved: 0,
actual total: 19200, total with overprovisioning: 19200; new used:
500,reserved:0; movedfromreserved: false,moveToReserveredfalse
2015-01-09 11:08:18,169 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) release mem from host: 1, old used:
1342177280,reserved: 0, total: 16420503552; new used:
1073741824,reserved:0; movedfromreserved: false,moveToReserveredfalse
2015-01-09 11:08:18,189 WARN
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null)
Exception while trying to start secondary storage vm
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[SecondaryStorageVm|s-152-VM]Scope=interface
com.cloud.dc.DataCenter; id=1
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:728)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:471)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:464)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.startSecStorageVm(SecondaryStorageManagerImpl.java:269)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.allocCapacity(SecondaryStorageManagerImpl.java:696)
at
com.cloud.storage.secondary.SecondaryStorageManagerImpl.expandPool(SecondaryStorageManagerImpl.java:1307)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:121)
at
com.cloud.secstorage.PremiumSecondaryStorageManagerImpl.scanPool(PremiumSecondaryStorageManagerImpl.java:52)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:104)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
at
com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
2015-01-09 11:08:18,192 INFO
[storage.secondary.SecondaryStorageManagerImpl] (secstorage-1:null) Unable
to start secondary storage vm for standby capacity, secStorageVm vm Id :
152, will recycle it and start a new one
2015-01-09 11:08:18,196 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) VM is already stopped: VM[SecondaryStorageVm|s-152-VM]
2015-01-09 11:08:18,209 DEBUG [cloud.capacity.CapacityManagerImpl]
(secstorage-1:null) VM state transitted from :Stopped to Expunging with
event: ExpungeOperationvm's original host id: null new host id: null host
id before state transition: null
2015-01-09 11:08:18,211 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-816644131: Sending { Cmd , MgmtId:
7501364227543, via: 1, Ver: v1, Flags: 100111,
[{"StartCommand":{"vm":{"id":2,"name":"v-2-VM","type":"ConsoleProxy","cpus":1,"speed":500,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"Debian
GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP type=consoleproxy
host=192.168.0.10 port=8250 name=v-2-VM premium=true zone=1 pod=1
guid=Proxy.2 proxy_vm=2 disable_rp_filter=true eth2ip=192.168.0.111
eth2mask=255.255.255.0 gateway=192.168.0.1 eth0ip=169.254.0.22
eth0mask=255.255.0.0 eth1ip=192.168.0.105 eth1mask=255.255.255.0
mgmtcidr=192.168.0.0/24
localgw=192.168.0.1 internaldns1=8.8.8.8 internaldns2=8.8.4.4 dns1=8.8.8.8
dns2=8.8.4.4","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"vncPassword":"c121518cceb6351f","params":{},"uuid":"0922ad08-05ca-4838-b97c-7b3855d277df","disks":[{"id":2,"name":"ROOT-2","mountPoint":"/var/lib/libvirt/images/","path":"aaa87362-beb7-4f00-9f2c-e3042f4a2025","size":0,"type":"ROOT","storagePoolType":"Filesystem","storagePoolUuid":"89e750c4-79af-4ed3-bee6-53fcec68ac96","deviceId":0}],"nics":[{"deviceId":2,"networkRateMbps":200,"defaultNic":true,"uuid":"5a555f14-1c0d-4eab-9d3b-c02603df1c52","ip":"192.168.0.111","netmask":"255.255.255.0","gateway":"192.168.0.1","mac":"06:ac:94:00:00:0c","dns1":"8.8.8.8","dns2":"8.8.4.4","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":true,"name":"cloudbr0"},{"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"6051ade4-661d-43fd-a07b-9a58df26d45a","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},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"b9fc57e7-cc45-4a64-816b-9177716d6952","ip":"192.168.0.105","netmask":"255.255.255.0","gateway":"192.168.0.1","mac":"06:a8:4a:00:00:06","broadcastType":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"cloudbr0"}]},"hostIp":"192.168.0.10","wait":0}},{"check.CheckSshCommand":{"ip":"169.254.0.22","port":3922,"interval":6,"retries":100,"name":"v-2-VM","wait":0}}]
}
2015-01-09 11:08:18,213 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Destroying vm VM[SecondaryStorageVm|s-152-VM]
2015-01-09 11:08:18,213 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Cleaning up NICS
2015-01-09 11:08:18,213 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Cleaning network for vm: 152
2015-01-09 11:08:18,218 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers to update status.
2015-01-09 11:08:18,220 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
2015-01-09 11:08:18,243 DEBUG [network.guru.DirectNetworkGuru]
(secstorage-1:null) Deallocate network: networkId: 204, ip: 192.168.0.112
2015-01-09 11:08:18,259 DEBUG [agent.transport.Request]
(AgentManager-Handler-12:null) Seq 1-816644131: Processing: { Ans: ,
MgmtId: 7501364227543, via: 1, Ver: v1, Flags: 110,
[{"StartAnswer":{"vm":{"id":2,"name":"v-2-VM","type":"ConsoleProxy","cpus":1,"speed":500,"minRam":1073741824,"maxRam":1073741824,"arch":"x86_64","os":"Debian
GNU/Linux 5.0 (32-bit)","bootArgs":" template=domP type=consoleproxy
host=192.168.0.10 port=8250 name=v-2-VM premium=true zone=1 pod=1
guid=Proxy.2 proxy_vm=2 disable_rp_filter=true eth2ip=192.168.0.111
eth2mask=255.255.255.0 gateway=192.168.0.1 eth0ip=169.254.0.22
eth0mask=255.255.0.0 eth1ip=192.168.0.105 eth1mask=255.255.255.0
mgmtcidr=192.168.0.0/24
localgw=192.168.0.1 internaldns1=8.8.8.8 internaldns2=8.8.4.4 dns1=8.8.8.8
dns2=8.8.4.4","rebootOnCrash":false,"enableHA":false,"limitCpuUse":false,"vncPassword":"c121518cceb6351f","vncAddr":"192.168.0.10","params":{},"uuid":"0922ad08-05ca-4838-b97c-7b3855d277df","disks":[{"id":2,"name":"ROOT-2","mountPoint":"/var/lib/libvirt/images/","path":"aaa87362-beb7-4f00-9f2c-e3042f4a2025","size":0,"type":"ROOT","storagePoolType":"Filesystem","storagePoolUuid":"89e750c4-79af-4ed3-bee6-53fcec68ac96","deviceId":0}],"nics":[{"deviceId":2,"networkRateMbps":200,"defaultNic":true,"uuid":"5a555f14-1c0d-4eab-9d3b-c02603df1c52","ip":"192.168.0.111","netmask":"255.255.255.0","gateway":"192.168.0.1","mac":"06:ac:94:00:00:0c","dns1":"8.8.8.8","dns2":"8.8.4.4","broadcastType":"Vlan","type":"Guest","broadcastUri":"vlan://untagged","isolationUri":"ec2://untagged","isSecurityGroupEnabled":true,"name":"cloudbr0"},{"deviceId":0,"networkRateMbps":-1,"defaultNic":false,"uuid":"6051ade4-661d-43fd-a07b-9a58df26d45a","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},{"deviceId":1,"networkRateMbps":-1,"defaultNic":false,"uuid":"b9fc57e7-cc45-4a64-816b-9177716d6952","ip":"192.168.0.105","netmask":"255.255.255.0","gateway":"192.168.0.1","mac":"06:a8:4a:00:00:06","broadcastType":"Native","type":"Management","isSecurityGroupEnabled":false,"name":"cloudbr0"}]},"result":false,"details":"org.libvirt.LibvirtException:
Storage volume not found: no storage vol with matching name
'aaa87362-beb7-4f00-9f2c-e3042f4a2025'","wait":0}},{"Answer":{"result":false,"details":"Stopped
by previous failure","wait":0}}] }
2015-01-09 11:08:18,259 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-12:null) Seq 1-816644131: No more commands found
2015-01-09 11:08:18,259 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-816644131: Received: { Ans: , MgmtId:
7501364227543, via: 1, Ver: v1, Flags: 110, { StartAnswer, Answer } }
2015-01-09 11:08:18,265 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 routers to update status.
2015-01-09 11:08:18,267 DEBUG
[network.router.VirtualNetworkApplianceManagerImpl]
(RouterStatusMonitor-1:null) Found 0 networks to update RvR status.
2015-01-09 11:08:18,272 INFO [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Unable to start VM on Host[-1-Routing] due to
org.libvirt.LibvirtException: Storage volume not found: no storage vol with
matching name 'aaa87362-beb7-4f00-9f2c-e3042f4a2025'
2015-01-09 11:08:18,282 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Removed nic id=604
2015-01-09 11:08:18,292 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Cleaning up resources for the vm
VM[ConsoleProxy|v-2-VM] in Starting state
2015-01-09 11:08:18,295 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-816644132: Sending { Cmd , MgmtId:
7501364227543, via: 1, Ver: v1, Flags: 100111,
[{"StopCommand":{"isProxy":false,"vmName":"v-2-VM","wait":0}}] }
2015-01-09 11:08:18,315 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Removed nic id=605
2015-01-09 11:08:18,345 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Removed nic id=606
2015-01-09 11:08:18,374 DEBUG [cloud.network.NetworkManagerImpl]
(secstorage-1:null) Removed nic id=607
2015-01-09 11:08:18,375 DEBUG [cloud.storage.StorageManagerImpl]
(secstorage-1:null) Cleaning storage for vm: 152
2015-01-09 11:08:18,398 DEBUG [cloud.storage.StorageManagerImpl]
(secstorage-1:null) Expunging Vol[152|vm=152|ROOT]
2015-01-09 11:08:18,403 DEBUG [cloud.storage.StorageManagerImpl]
(secstorage-1:null) Marking volume that was never created as destroyed:
Vol[152|vm=152|ROOT]
2015-01-09 11:08:18,425 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(secstorage-1:null) Expunged VM[SecondaryStorageVm|s-152-VM]
2015-01-09 11:08:18,442 INFO
[cloud.secstorage.PremiumSecondaryStorageManagerImpl] (secstorage-1:null)
Primary secondary storage is not even started, wait until next turn
2015-01-09 11:08:18,509 DEBUG [agent.transport.Request]
(AgentManager-Handler-13:null) Seq 1-816644132: Processing: { Ans: ,
MgmtId: 7501364227543, via: 1, Ver: v1, Flags: 110,
[{"StopAnswer":{"vncPort":0,"result":true,"wait":0}}] }
2015-01-09 11:08:18,510 DEBUG [agent.manager.AgentAttache]
(AgentManager-Handler-13:null) Seq 1-816644132: No more commands found
2015-01-09 11:08:18,510 DEBUG [agent.transport.Request]
(consoleproxy-1:null) Seq 1-816644132: Received: { Ans: , MgmtId:
7501364227543, via: 1, Ver: v1, Flags: 110, { StopAnswer } }
2015-01-09 11:08:18,536 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking NiciraNvp to release
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:18,536 DEBUG [network.element.NiciraNvpElement]
(consoleproxy-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network defaultGuestNetwork
2015-01-09 11:08:18,536 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking JuniperSRX to release
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:18,537 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Netscaler to release
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:18,537 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking F5BigIP to release
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:18,537 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:18,537 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking BigSwitchVnsElement to release
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:18,537 DEBUG [network.element.BigSwitchVnsElement]
(consoleproxy-1:null) Checking if BigSwitchVnsElement can handle service
Connectivity on network defaultGuestNetwork
2015-01-09 11:08:18,537 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VirtualRouter to release
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:18,537 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Ovs to release
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:18,537 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking SecurityGroupProvider to release
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:18,537 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VpcVirtualRouter to release
Nic[5-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-192.168.0.111]
2015-01-09 11:08:18,543 DEBUG [network.guru.ControlNetworkGuru]
(consoleproxy-1:null) Released nic: NicProfile[6-2-null-null-null
2015-01-09 11:08:18,555 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking NiciraNvp to release
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,555 DEBUG [network.element.NiciraNvpElement]
(consoleproxy-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network null
2015-01-09 11:08:18,555 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking JuniperSRX to release
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,555 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Netscaler to release
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,555 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking F5BigIP to release
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,555 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,555 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking BigSwitchVnsElement to release
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,555 DEBUG [network.element.BigSwitchVnsElement]
(consoleproxy-1:null) Checking if BigSwitchVnsElement can handle service
Connectivity on network null
2015-01-09 11:08:18,556 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VirtualRouter to release
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,556 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Ovs to release
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,556 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking SecurityGroupProvider to release
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,556 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VpcVirtualRouter to release
Nic[6-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,563 DEBUG [dc.dao.DataCenterIpAddressDaoImpl]
(consoleproxy-1:null) Releasing ip address for
reservationId=09d9d4b5-2cf9-487e-aa85-cd98be5b03d9, instance=7
2015-01-09 11:08:18,564 DEBUG [network.guru.PodBasedNetworkGuru]
(consoleproxy-1:null) Released nic: NicProfile[7-2-null-null-null
2015-01-09 11:08:18,576 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking NiciraNvp to release
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,576 DEBUG [network.element.NiciraNvpElement]
(consoleproxy-1:null) Checking if NiciraNvpElement can handle service
Connectivity on network null
2015-01-09 11:08:18,576 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking JuniperSRX to release
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,576 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Netscaler to release
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,576 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking F5BigIP to release
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,576 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking CiscoNexus1000vVSM to release
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,576 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking BigSwitchVnsElement to release
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,576 DEBUG [network.element.BigSwitchVnsElement]
(consoleproxy-1:null) Checking if BigSwitchVnsElement can handle service
Connectivity on network null
2015-01-09 11:08:18,577 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VirtualRouter to release
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,577 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking Ovs to release
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,577 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking SecurityGroupProvider to release
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,577 DEBUG [cloud.network.NetworkManagerImpl]
(consoleproxy-1:null) Asking VpcVirtualRouter to release
Nic[7-2-09d9d4b5-2cf9-487e-aa85-cd98be5b03d9-null]
2015-01-09 11:08:18,577 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Successfully released network resources for the vm
VM[ConsoleProxy|v-2-VM]
2015-01-09 11:08:18,577 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Successfully cleanued up resources for the vm
VM[ConsoleProxy|v-2-VM] in Starting state
2015-01-09 11:08:18,582 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Root volume is ready, need to place VM in volume's
cluster
2015-01-09 11:08:18,583 DEBUG [cloud.vm.VirtualMachineManagerImpl]
(consoleproxy-1:null) Vol[2|vm=2|ROOT] is READY, changing deployment plan
to use this pool's dcId: 1 , podId: 1 , and clusterId: 1
2015-01-09 11:08:18,584 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) DeploymentPlanner allocation algorithm: random
2015-01-09 11:08:18,585 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Trying to allocate a host and storage pools from
dc:1, pod:1,cluster:1, requested cpu: 500, requested ram: 1073741824
2015-01-09 11:08:18,585 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Is ROOT volume READY (pool already allocated)?: Yes
2015-01-09 11:08:18,585 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Searching resources only under specified Cluster: 1
2015-01-09 11:08:18,596 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Checking resources in Cluster: 1 under Pod: 1
2015-01-09 11:08:18,596 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) Looking for hosts in dc: 1 pod:1
cluster:1
2015-01-09 11:08:18,600 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) FirstFitAllocator has 1 hosts to
check for allocation: [Host[-1-Routing]]
2015-01-09 11:08:18,604 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) Found 1 hosts for allocation
after prioritization: [Host[-1-Routing]]
2015-01-09 11:08:18,604 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) Looking for speed=500Mhz,
Ram=1024
2015-01-09 11:08:18,604 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) Host name: localhost, hostId: 1
is in avoid set, skipping this and trying other available hosts
2015-01-09 11:08:18,605 DEBUG [allocator.impl.FirstFitAllocator]
(consoleproxy-1:FirstFitRoutingAllocator) Host Allocator returning 0
suitable hosts
2015-01-09 11:08:18,605 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) No suitable hosts found
2015-01-09 11:08:18,605 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) No suitable hosts found under this Cluster: 1
2015-01-09 11:08:18,605 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Could not find suitable Deployment Destination for
this VM under any clusters, returning.
2015-01-09 11:08:18,607 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) DeploymentPlanner allocation algorithm: random
2015-01-09 11:08:18,607 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Trying to allocate a host and storage pools from
dc:1, pod:1,cluster:null, requested cpu: 500, requested ram: 1073741824
2015-01-09 11:08:18,607 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Is ROOT volume READY (pool already allocated)?: No
2015-01-09 11:08:18,607 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Searching resources only under specified Pod: 1
2015-01-09 11:08:18,609 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Listing clusters in order of aggregate capacity, that
have (atleast one host with) enough CPU and RAM capacity under this Pod: 1
2015-01-09 11:08:18,610 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) CPUOverprovisioningFactor considered: 1.0
2015-01-09 11:08:18,614 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) Removing from the clusterId list these clusters from
avoid set: [1]
2015-01-09 11:08:18,614 DEBUG [cloud.deploy.FirstFitPlanner]
(consoleproxy-1:null) No clusters found after removing disabled clusters
and clusters in avoid list, returning.
2015-01-09 11:08:18,639 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) VM state transitted from :Starting to Stopped with
event: OperationFailedvm's original host id: null new host id: null host id
before state transition: 1
2015-01-09 11:08:18,648 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) Hosts's actual total CPU: 19200 and CPU after
applying overprovisioning: 19200
2015-01-09 11:08:18,649 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) release cpu from host: 1, old used: 500,reserved: 0,
actual total: 19200, total with overprovisioning: 19200; new used:
0,reserved:0; movedfromreserved: false,moveToReserveredfalse
2015-01-09 11:08:18,649 DEBUG [cloud.capacity.CapacityManagerImpl]
(consoleproxy-1:null) release mem from host: 1, old used:
1073741824,reserved: 0, total: 16420503552; new used: 0,reserved:0;
movedfromreserved: false,moveToReserveredfalse
2015-01-09 11:08:18,661 WARN [cloud.consoleproxy.ConsoleProxyManagerImpl]
(consoleproxy-1:null) Exception while trying to start console proxy
com.cloud.exception.InsufficientServerCapacityException: Unable to create a
deployment for VM[ConsoleProxy|v-2-VM]Scope=interface
com.cloud.dc.DataCenter; id=1
at
com.cloud.vm.VirtualMachineManagerImpl.advanceStart(VirtualMachineManagerImpl.java:728)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:471)
at
com.cloud.vm.VirtualMachineManagerImpl.start(VirtualMachineManagerImpl.java:464)
at
com.cloud.consoleproxy.ConsoleProxyManagerImpl.startProxy(ConsoleProxyManagerImpl.java:632)
at
com.cloud.consoleproxy.ConsoleProxyManagerImpl.allocCapacity(ConsoleProxyManagerImpl.java:1166)
at
com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:1985)
at
com.cloud.consoleproxy.ConsoleProxyManagerImpl.expandPool(ConsoleProxyManagerImpl.java:175)
at com.cloud.vm.SystemVmLoadScanner.loadScan(SystemVmLoadScanner.java:111)
at com.cloud.vm.SystemVmLoadScanner.access$100(SystemVmLoadScanner.java:33)
at
com.cloud.vm.SystemVmLoadScanner$1.reallyRun(SystemVmLoadScanner.java:81)
at com.cloud.vm.SystemVmLoadScanner$1.run(SystemVmLoadScanner.java:72)
at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:471)
at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:304)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:178)
at
java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:293)
at
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
at
java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
at java.lang.Thread.run(Thread.java:745)
最後となりますが、追記について承知致しました。
ログを確認している最中ですが、お礼の返信が3日以上
あいてしまいましたので、取り急ぎご返信まで。
重ねてとなりますが、ありがとうございました。
2015年1月6日 3:49 giraffe.forest <giraffe.forest ＠ wh.commufa.jp>:
> 永喜多さん
>
> こんにちは CloudStackユーザ会の中谷と申します。
> どうぞよろしくお願いいたします。
>
> 試しに似た構成でインストールしてみました。
> 結果として，うまく動かすことができました。
> まず参考として環境情報を記載いたします。
>
> ・使用したマニュアル
> http://cloudstack.apache.org/docs/ja-JP/Apache_CloudStack/
> 4.1.1/html/Installation_Guide/installation.html
>
> ・1サーバ(management-serverとagentの同居)
> ・1NIC (10.0.0.3)
> ・Apache CloudStack 4.1.1
> ・SystemVMテンプレート：acton-systemvm-02062012.qcow2.bz2
> ・CentOS6.6 64bit
> ・プライマリストレージ：ローカルディスクを使用(NFSアクセスではない)
> ・セカンダリストレージ：NFSv3アクセス
> ・OS環境設定
> [root ＠ kvm01 ~]# rpm -qa | grep kvm
> qemu-kvm-0.12.1.2-2.448.el6_6.x86_64
> [root ＠ kvm01 ~]# rpm -qa | grep libvirt
> libvirt-client-0.10.2-46.el6_6.2.x86_64
> libvirt-0.10.2-46.el6_6.2.x86_64
> [root ＠ kvm01 ~]# rpm -qa | grep cloudstack
> cloudstack-awsapi-4.1.1-0.el6.x86_64
> cloudstack-management-4.1.1-0.el6.x86_64
> cloudstack-agent-4.1.1-0.el6.x86_64
> cloudstack-common-4.1.1-0.el6.x86_64
> [root ＠ kvm01 ~]#
> [root ＠ kvm01 ~]# ifconfig
> cloudbr0 Link encap:Ethernet HWaddr 00:0C:29:C4:2E:77
> inet addr:10.0.0.3 Bcast:10.0.0.255 Mask:255.255.255.0
> UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
> RX packets:453792 errors:0 dropped:0 overruns:0 frame:0
> TX packets:280715 errors:0 dropped:0 overruns:0 carrier:0
> collisions:0 txqueuelen:0
> RX bytes:653734368 (623.4 MiB) TX bytes:24991359 (23.8 MiB)
>
> eth0 Link encap:Ethernet HWaddr 00:0C:29:C4:2E:77
> UP BROADCAST RUNNING MULTICAST MTU:1500 Metric:1
> RX packets:466261 errors:0 dropped:0 overruns:0 frame:0
> TX packets:283903 errors:0 dropped:0 overruns:0 carrier:0
> collisions:0 txqueuelen:1000
> RX bytes:660823626 (630.2 MiB) TX bytes:25160943 (23.9 MiB)
>
> lo Link encap:Local Loopback
> inet addr:127.0.0.1 Mask:255.0.0.0
> UP LOOPBACK RUNNING MTU:65536 Metric:1
> RX packets:62030 errors:0 dropped:0 overruns:0 frame:0
> TX packets:62030 errors:0 dropped:0 overruns:0 carrier:0
> collisions:0 txqueuelen:0
> RX bytes:11016103 (10.5 MiB) TX bytes:11016103 (10.5 MiB)
>
> [root ＠ kvm01 ~]#
> [root ＠ kvm01 ~]# netstat -rn
> Kernel IP routing table
> Destination Gateway Genmask Flags MSS Window irtt
> Iface
> 10.0.0.0 0.0.0.0 255.255.255.0 U 0 0 0
> cloudbr0
> 0.0.0.0 10.0.0.1 0.0.0.0 UG 0 0 0
> cloudbr0
> [root ＠ kvm01 ~]#
> [root ＠ kvm01 ~]# hostname -f
> kvm01.dom.local
> [root ＠ kvm01 ~]# ping www.cloudstack.org
> PING www.apache.org (192.87.106.229) 56(84) bytes of data.
> 64 bytes from aurora-2012.apache.org (192.87.106.229): icmp_seq=1 ttl=51
> time=258 ms
> 64 bytes from aurora-2012.apache.org (192.87.106.229): icmp_seq=2 ttl=51
> time=258 ms
> 64 bytes from aurora-2012.apache.org (192.87.106.229): icmp_seq=3 ttl=51
> time=259 ms
> ^C
> --- www.apache.org ping statistics ---
> 4 packets transmitted, 3 received, 25% packet loss, time 3411ms
> rtt min/avg/max/mdev = 258.247/258.885/259.743/0.861 ms
> [root ＠ kvm01 ~]#
> [root ＠ kvm01 ~]# getenforce
> Disabled
> [root ＠ kvm01 ~]#
>
> システムVMとインスタンスが起動しています。
> [root ＠ kvm01 ~]# virsh list
> Id Name State
> ----------------------------------------------------
> 1 s-1-VM running
> 2 v-2-VM running
> 3 r-7-VM running
> 4 i-2-6-VM running
>
> [root ＠ kvm01 ~]#
>
> ※システムVM自体は、WebUI上でStoppedでしたので、WebUIから2台とも削除致しました
>> その後、自動作成されずにおります
>>
>
> いくつか設定を確認してみてください。
>
> (1)ローカルストレージ利用時の注意点
> ・永喜多さんの環境もプライマリストレージはNFSではなく，ローカルストレージでしょうか。
> その場合，ゾーン作成時にLocal Storage Enabledをチェック(有効)にしましたでしょうか。
> 当方の操作では
> WebUIにログイン後
> 「CloudStackを使用したことがあるので、このガイドをスキップする。」
> を選択し
> インフラストラクチャ->ゾーン->ゾーンの追加
> でゾーンを追加しています。
> その場合はゾーン作成ウィザードにてLocal Storage Enabledの項目が画面の下の方にでてきます。
>
> ・WebUIのグローバル設定で
> system.vm.use.local.storageはtrueに設定してください。
> 設定後はmanagement-serverのプロセス再起動が必要です。
>
> (2)management-serverのIPアドレス設定の確認
>
> ・WebUIのグローバル設定で
> hostがサーバのIPアアドレスに設定はされているか確認してください。
>
> ・サーバの設定ファイル：/etc/cloudstack/management/db.properties
> にて，以下パラメータが正しく設定されているか確認してください。
> 例：
> ：
> cluster.node.IP=10.0.0.3
> ：
> db.cloud.host=localhost
> ：
>
> ※KVM環境にmanagement-serverを同居させておくと
> KVMのデフォルトネットワーク(virbr0)のIPが割り当てられ邪魔をする場合があります。
> 以下のように最初から無効にしておくと便利です。
>
> [root ＠ kvm01 ~]# virsh net-list --all
> Name State Autostart Persistent
> --------------------------------------------------
> default active yes yes
>
> [root ＠ kvm01 ~]# virsh net-destroy default
> Network default destroyed
>
> [root ＠ kvm01 ~]# virsh net-autostart default --disable
> Network default unmarked as autostarted
>
> [root ＠ kvm01 ~]# virsh net-list --all
> Name State Autostart Persistent
> --------------------------------------------------
> default inactive no yes
>
> [root ＠ kvm01 ~]#
>
> (3)仮想スイッチ名の確認
> WebUIの
> インフラストラクチャ->ゾーン->[ゾーンを選択]->Physical Network 1->[Physical Networkを選択]->
> ゲスト：KVM トラフィックのラベル:cloudbr0
> 管理：KVM トラフィックのラベル:cloudbr0
> のようにラベル名が
> サーバに設定した仮想スイッチ名と同一になっているか確認してください。
>
> (4)その他
> WebUIのグローバル設定で
> secstorage.allowed.internal.sites
> も設定してみてください。
> 例：10.0.0.0/24
>
>
> 本題にはいります。
> これら設定を確認した後に
> 1)ログをtailしてください。
> [root ＠ kvm01 ~]# tail -f /var/log/cloudstack/management/management-server.
> log
> [root ＠ kvm01 ~]# tail -f /var/log/cloudstack/agent/agent.log
> 2)インフラストラクチャ->ゾーン->[ゾーンを選択]にてゾーンを無効化
> 3)インフラストラクチャ->ゾーン->[ゾーンを選択]にてゾーンを有効化
> 上記操作実施後，しばらくすると例外エラーが発生していると思われます。
> その例外エラーの上100行程度の情報が解析のヒントになります。
>
> ERROR以外にDEBUGやINFOにも情報がうもれてしまっているので
> 例外エラーの上を確認していきます。
>
> 例：
> この上
> 2015-01-06 03:13:02,026 INFO [user.vm.DeployVMCmd]
> (Job-Executor-10:job-10) Unable to create a deployment for VM[User|vm02]
> com.cloud.exception.InsufficientServerCapacityException: Unable to create
> a deployment for VM[User|vm02]Scope=interface com.cloud.dc.DataCenter; id=1
> at org.apache.cloudstack.engine.cloud.entity.api.
> VMEntityManagerImpl.reserveVirtualMachine(VMEntityManagerImpl.java:186)
> at org.apache.cloudstack.engine.cloud.entity.api.
> VirtualMachineEntityImpl.reserve(VirtualMachineEntityImpl.java:198)
> at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(
> UserVmManagerImpl.java:3870)
> at com.cloud.vm.UserVmManagerImpl.startVirtualMachine(
> UserVmManagerImpl.java:3464)
>
>
> 以上です。
>
> 追記：
> もしSystemVMが起動するようになったら今度はVMインスタンスを起動すると思いますが
> ローカルストレージ利用時は初期登録されているコンピュートオファリングは利用できません。
> ストレージの種類：localの
> コンピュートオファリングを別途作成し利用する必要があります。
> またセキュリティグループの解放も必要です。
>
>
>
> -----Original Message----- From: 永喜多
> Sent: Monday, January 05, 2015 8:38 PM
> To: users ＠ cloudstack.jp
> Subject: [cloudstack-users:0409]【質問】システムVM2台の作成、起動について（CentOS6.6+KVM+ver4.1.1）
>
>
>
> はじめまして、永喜多と申します。
>
>
> 掲題の件について、後述の環境にて構築中です。
>
>
> management-server.logや、agent.logを確認しても、
>
> VM2台の作成について問題切り分けができなくなりました。
> このため、可能であれば解決に向け、確認箇所のご相談ができればと存じます。
> ※システムVM自体は、WebUI上でStoppedでしたので、WebUIから2台とも削除致しました
> その後、自動作成されずにおります
>
>
> ▽環境
> ----------
> OS：CentOS6.6
>
> HV：KVM / qemu-kvm-0.12.1.2-2.448.el6_6.x86_64
>
> DB ：mysql-server-5.1.73-3.el6_5.x86_64
>
> ネットワーク：Basic
>
> ipv6：no
>
> IPアドレス：static 1つ
>
> CloudStackシステムテンプレート：4.1.1
>
> サーバは1台、/mnt/secondaryは別PC
>
> ※HostとManagementは同一サーバ：192.168.0.10
> secondary：192.168.0.2
> ----------
>
>
> 以下は、agentとmanagementのログとなります。
>
>
> ▽agent.log
>
> [root ＠ cloud ~]# tail -n 15 /var/log/cloudstack/agent/agent.log
> at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.execute(
> LibvirtComputingResource.java:2304)
> at com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.
> executeRequest(LibvirtComputingResource.java:1094)
> at com.cloud.agent.Agent.processRequest(Agent.java:525)
> at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:852)
> at com.cloud.utils.nio.Task.run(Task.java:83)
> at java.util.concurrent.ThreadPoolExecutor.runWorker(
> ThreadPoolExecutor.java:1145)
> at java.util.concurrent.ThreadPoolExecutor$Worker.run(
> ThreadPoolExecutor.java:615)
> at java.lang.Thread.run(Thread.java:745)
> 2015-01-05 17:22:16,943 INFO [cloud.agent.Agent]
> (agentRequest-Handler-4:null) Proccess agent ready command, agent id = 3
> 2015-01-05 17:22:16,943 INFO [cloud.agent.Agent]
> (agentRequest-Handler-4:null) Set agent id 3
> 2015-01-05 17:22:16,945 INFO [cloud.agent.Agent]
> (agentRequest-Handler-4:null) Ready command is processed: agent id = 3
> 2015-01-05 17:22:17,062 INFO [cloud.agent.Agent]
> (agentRequest-Handler-5:null) Proccess agent ready command, agent id = 3
> 2015-01-05 17:22:17,063 INFO [cloud.agent.Agent]
> (agentRequest-Handler-5:null) Set agent id 3
> 2015-01-05 17:22:17,065 INFO [cloud.agent.Agent]
> (agentRequest-Handler-5:null) Ready command is processed: agent id = 3
> 2015-01-05 17:22:20,867 INFO [cloud.agent.Agent] (Agent-Handler-5:null)
> Connected to the server
>
>
>
>
>
> ▽management.log
> [root ＠ cloud ~]# tail -n 30 /var/log/cloudstack/
> management/management-server.log
> 2015-01-05 20:12:16,288 DEBUG [agent.manager.AgentManagerImpl]
> (AgentManager-Handler-8:null) Ping from 3
> 2015-01-05 20:12:16,676 DEBUG [agent.transport.Request]
> (StatsCollector-1:null) Seq 3-2055733424: Received: { Ans: , MgmtId:
> 179176544198247, via: 3, Ver: v1, Flags: 10, { GetHostStatsAnswer } }
> 2015-01-05 20:12:28,769 DEBUG [cloud.server.StatsCollector]
> (StatsCollector-2:null) VmStatsCollector is running...
> 2015-01-05 20:12:29,323 DEBUG [cloud.server.StatsCollector]
> (StatsCollector-3:null) StorageCollector is running...
> 2015-01-05 20:12:29,328 DEBUG [cloud.server.StatsCollector]
> (StatsCollector-3:null) There is no secondary storage VM for secondary
> storage host nfs://192.168.0.2/mnt/secondary
> 2015-01-05 20:12:41,801 DEBUG [storage.secondary.SecondaryStorageManagerImpl]
> (secstorage-1:null) Primary storage is not ready, wait until it is ready to
> launch secondary storage vm
> 2015-01-05 20:12:41,801 DEBUG [storage.secondary.SecondaryStorageManagerImpl]
> (secstorage-1:null) Zone 1 is not ready to launch secondary storage VM yet
> 2015-01-05 20:12:42,360 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
> (consoleproxy-1:null) Primary storage is not ready, wait until it is ready
> to launch console proxy
> 2015-01-05 20:12:42,361 DEBUG [cloud.consoleproxy.ConsoleProxyManagerImpl]
> (consoleproxy-1:null) Zone 1 is not ready to launch console proxy yet
> 2015-01-05 20:12:42,757 DEBUG [network.router.
> VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0
> routers to update status.
> 2015-01-05 20:12:42,758 DEBUG [network.router.
> VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0
> networks to update RvR status.
> 2015-01-05 20:12:42,813 DEBUG [network.router.
> VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0
> routers to update status.
> 2015-01-05 20:12:42,815 DEBUG [network.router.
> VirtualNetworkApplianceManagerImpl] (RouterStatusMonitor-1:null) Found 0
> networks to update RvR status.
> 2015-01-05 20:12:42,892 DEBUG [cloud.alert.AlertManagerImpl]
> (CapacityChecker:null) Running Capacity Checker ...
> 2015-01-05 20:12:42,892 DEBUG [cloud.alert.AlertManagerImpl]
> (CapacityChecker:null) recalculating system capacity
> 2015-01-05 20:12:42,892 DEBUG [cloud.alert.AlertManagerImpl]
> (CapacityChecker:null) Executing cpu/ram capacity update
> 2015-01-05 20:12:42,903 DEBUG [cloud.capacity.CapacityManagerImpl]
> (CapacityChecker:null) Found 0 VMs on host 3
> 2015-01-05 20:12:42,905 DEBUG [cloud.capacity.CapacityManagerImpl]
> (CapacityChecker:null) Found 0 VM, not running on host 3
> 2015-01-05 20:12:42,909 DEBUG [cloud.capacity.CapacityManagerImpl]
> (CapacityChecker:null) No need to calibrate cpu capacity, host:3 usedCpu: 0
> reservedCpu: 0
> 2015-01-05 20:12:42,909 DEBUG [cloud.capacity.CapacityManagerImpl]
> (CapacityChecker:null) No need to calibrate memory capacity, host:3
> usedMem: 0 reservedMem: 0
> 2015-01-05 20:12:42,909 DEBUG [cloud.alert.AlertManagerImpl]
> (CapacityChecker:null) Done executing cpu/ram capacity update
> 2015-01-05 20:12:42,909 DEBUG [cloud.alert.AlertManagerImpl]
> (CapacityChecker:null) Executing storage capacity update
> 2015-01-05 20:12:42,929 DEBUG [cloud.storage.StorageManagerImpl]
> (CapacityChecker:null) Successfully set Capacity - 105421733888 for
> capacity type - 3 , DataCenterId - 1, HostOrPoolId - 200, PodId 1
> 2015-01-05 20:12:42,929 DEBUG [cloud.alert.AlertManagerImpl]
> (CapacityChecker:null) Done executing storage capacity update
> 2015-01-05 20:12:42,929 DEBUG [cloud.alert.AlertManagerImpl]
> (CapacityChecker:null) Executing capacity updates for public ip and Vlans
> 2015-01-05 20:12:42,939 DEBUG [cloud.alert.AlertManagerImpl]
> (CapacityChecker:null) Done capacity updates for public ip and Vlans
> 2015-01-05 20:12:42,939 DEBUG [cloud.alert.AlertManagerImpl]
> (CapacityChecker:null) Executing capacity updates for private ip
> 2015-01-05 20:12:42,949 DEBUG [cloud.alert.AlertManagerImpl]
> (CapacityChecker:null) Done executing capacity updates for private ip
> 2015-01-05 20:12:42,949 DEBUG [cloud.alert.AlertManagerImpl]
> (CapacityChecker:null) Done recalculating system capacity
> 2015-01-05 20:12:42,974 DEBUG [cloud.alert.AlertManagerImpl]
> (CapacityChecker:null) Done running Capacity Checker ...
>
>
>
> 以上となります。
>
>
>
> 設定ファイル群の記載については、どこまで記述するのがよいか
> 不明瞭だったため、さしあたりログのみを記載させていただきました。
>
>
> システムVM2台の作成、起動について、ご教授頂けたら幸いです。
>
>
> --
>
> -------------------------------------------
> 永喜多
> mailto:E-Mail%3An ＠ gakita.me
> -------------------------------------------
>
>
>
>
>
> _______________________________________________
> users mailing list
> users ＠ cloudstack.jp
> http://ml.cloudstack.jp/mailman/listinfo/users
>
--
-------------------------------------------
永喜多
E-Mail:n ＠ gakita.me
-------------------------------------------
-------------- next part --------------
HTML$B$NE:IU%U%!%$%k$rJ]4I$7$^$7$?(B...
URL: <http://ml.cloudstack.jp/pipermail/users/attachments/20150109/d7c45cb1/attachment-0001.html>
users メーリングリストの案内