tdtmusic2 commented on issue #10094:
URL: https://github.com/apache/cloudstack/issues/10094#issuecomment-2541384620
>
> these entries seem to be consequential, as the host is already removed
from the DB. Can you try adding the host again and keep the log from the start
of the API call till the end? In addition can you add the log
/var/log/cloudstack/agent/agent.log from the KVM host?
>
Ok, here's the management server log entries:
```
2024-12-13 14:22:52,950 DEBUG [o.a.c.c.p.RootCACustomTrustManager]
(pool-44-thread-1:null) (logid:) A client/agent attempting connection from
address=172.xx.xx.84 has presented these certificate(s):
Certificate [1] :
Serial: 51e3a61b236e5658
Not Before:Fri Dec 13 02:21:01 EET 2024
Not After:Sat Dec 13 14:21:01 EET 2025
Signature Algorithm:SHA256withRSA
Version:3
Subject DN:C=cloudstack, O=cloudstack, OU=cloudstack, CN=NODE77
Issuer DN:CN=ca.cloudstack.apache.org
Alternative Names:[[7, 172.xx.xx.84], [2, 172.xx.xx.84]]
Certificate [2] :
Serial: 9bc3be57b932e564
Not Before:Thu Aug 01 02:50:35 EEST 2024
Not After:Sat Jul 25 14:50:35 EEST 2054
Signature Algorithm:SHA256withRSA
Version:3
Subject DN:CN=ca.cloudstack.apache.org
Issuer DN:CN=ca.cloudstack.apache.org
Alternative Names:null
2024-12-13 14:22:52,954 DEBUG [o.a.c.c.p.RootCACustomTrustManager]
(pool-44-thread-1:null) (logid:) Client/agent connection from ip=172.xx.xx.84
has been validated and trusted.
2024-12-13 14:22:53,017 WARN [o.a.c.f.j.i.AsyncJobMonitor]
(Timer-0:ctx-8f797682) (logid:0850baec) Task (job-85337) has been pending for
93328 seconds
2024-12-13 14:22:53,095 DEBUG [o.a.c.h.HAManagerImpl]
(BackgroundTaskPollManager-5:ctx-6b0e6db0) (logid:a37513cf) HA health check
task is running...
2024-12-13 14:22:53,472 DEBUG [c.c.a.t.Request]
(AgentManager-Handler-6:null) (logid:) Seq 0-4: Scheduling the first command {
Cmd , MgmtId: -1, via: 0, Ver: v1, Flags: 1,
[{"com.cloud.agent.api.StartupRoutingCommand":{"cpuSockets":"8","cpus":"128","speed":"1996","memory":"133189480448","dom0MinMemory":"1073741824","poolSync":"false","supportsClonedVolumes":"false","caps":"hvm,snapshot","pool":"/root","hypervisorType":"KVM","hostDetails":{"Host.OS.Kernel.Version":"5.14.0-503.15.1.el9_5.x86_64","com.cloud.network.Networks.RouterPrivateIpStrategy":"HostLocal","Host.OS.Version":"9.5","host.volume.encryption":"true","host.instance.conversion":"false","secured":"true","Host.OS":"AlmaLinux"},"hostTags":[],"groupDetails":{},"type":"Routing","dataCenter":"12","pod":"15","cluster":"15","guid":"b6788745-7c07-3aa2-aceb-6c49c497ceee-LibvirtComputingResource","name":"NODE77","id":"0","version":"4.19.1.3","privateIpAddress":"172.xx.xx.84","privateMacAddress":"34:80:0d:03:e7:10","privateNetmask
":"255.255.255.0","storageIpAddress":"172.xx.xx.84","storageNetmask":"255.255.255.0","storageMacAddress":"34:80:0d:03:e7:10","resourceName":"LibvirtComputingResource","gatewayIpAddress":"172.xx.xx.254","msHostList":"172.xx.xx.12,172.xx.xx.11,172.xx.xx.10","wait":"0","bypassHostMaintenance":"false"}},{"com.cloud.agent.api.StartupStorageCommand":{"totalSize":"(0
bytes)
0","poolInfo":{"uuid":"c925ad9d-7b05-4a6a-97c6-e564cd26257b","host":"172.xx.xx.84","localPath":"/var/lib/libvirt/images","hostPath":"/var/lib/libvirt/images","poolType":"Filesystem","capacityBytes":"(69.94
GB) 75094818816","availableBytes":"(66.66 GB)
71574978560"},"resourceType":"STORAGE_POOL","hostDetails":{},"type":"Storage","dataCenter":"12","pod":"15","guid":"b6788745-7c07-3aa2-aceb-6c49c497ceee-LibvirtComputingResource","name":"NODE77","id":"0","version":"4.19.1.3","resourceName":"LibvirtComputingResource","msHostList":"172.xx.xx.12,172.xx.xx.11,172.xx.xx.10","wait":"0","bypassHostMaintenance":"false"}}]
}
2024-12-13 14:22:53,479 DEBUG [c.c.a.t.Request]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Seq 0-4: Processing the
first command { Cmd , MgmtId: -1, via: 0, Ver: v1, Flags: 1,
[{"com.cloud.agent.api.StartupRoutingCommand":{"cpuSockets":"8","cpus":"128","speed":"1996","memory":"133189480448","dom0MinMemory":"1073741824","poolSync":"false","supportsClonedVolumes":"false","caps":"hvm,snapshot","pool":"/root","hypervisorType":"KVM","hostDetails":{"Host.OS.Kernel.Version":"5.14.0-503.15.1.el9_5.x86_64","com.cloud.network.Networks.RouterPrivateIpStrategy":"HostLocal","Host.OS.Version":"9.5","host.volume.encryption":"true","host.instance.conversion":"false","secured":"true","Host.OS":"AlmaLinux"},"hostTags":[],"groupDetails":{},"type":"Routing","dataCenter":"12","pod":"15","cluster":"15","guid":"b6788745-7c07-3aa2-aceb-6c49c497ceee-LibvirtComputingResource","name":"NODE77","id":"0","version":"4.19.1.3","privateIpAddress":"172.xx.xx.84","privateMacAddress":"34:80:0d:03:e7:10
","privateNetmask":"255.255.255.0","storageIpAddress":"172.xx.xx.84","storageNetmask":"255.255.255.0","storageMacAddress":"34:80:0d:03:e7:10","resourceName":"LibvirtComputingResource","gatewayIpAddress":"172.xx.xx.254","msHostList":"172.xx.xx.12,172.xx.xx.11,172.xx.xx.10","wait":"0","bypassHostMaintenance":"false"}},{"com.cloud.agent.api.StartupStorageCommand":{"totalSize":"(0
bytes)
0","poolInfo":{"uuid":"c925ad9d-7b05-4a6a-97c6-e564cd26257b","host":"172.xx.xx.84","localPath":"/var/lib/libvirt/images","hostPath":"/var/lib/libvirt/images","poolType":"Filesystem","capacityBytes":"(69.94
GB) 75094818816","availableBytes":"(66.66 GB)
71574978560"},"resourceType":"STORAGE_POOL","hostDetails":{},"type":"Storage","dataCenter":"12","pod":"15","guid":"b6788745-7c07-3aa2-aceb-6c49c497ceee-LibvirtComputingResource","name":"NODE77","id":"0","version":"4.19.1.3","resourceName":"LibvirtComputingResource","msHostList":"172.xx.xx.12,172.xx.xx.11,172.xx.xx.10","wait":"0","bypassHostMaintenance":"fa
lse"}}] }
2024-12-13 14:22:53,503 DEBUG [c.c.r.ResourceManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Dispatching resource
state event CREATE_HOST_VO_FOR_CONNECTED to CiscoVnmcElement
2024-12-13 14:22:53,503 DEBUG [c.c.r.ResourceManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Dispatching resource
state event CREATE_HOST_VO_FOR_CONNECTED to BareMetalDiscoverer
2024-12-13 14:22:53,503 DEBUG [c.c.r.ResourceManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Dispatching resource
state event CREATE_HOST_VO_FOR_CONNECTED to NetscalerElement
2024-12-13 14:22:53,503 DEBUG [c.c.r.ResourceManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Dispatching resource
state event CREATE_HOST_VO_FOR_CONNECTED to HypervServerDiscoverer
2024-12-13 14:22:53,503 DEBUG [c.c.r.ResourceManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Dispatching resource
state event CREATE_HOST_VO_FOR_CONNECTED to BaremetalPxeManagerImpl
2024-12-13 14:22:53,504 DEBUG [c.c.r.ResourceManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Dispatching resource
state event CREATE_HOST_VO_FOR_CONNECTED to XcpServerDiscoverer
2024-12-13 14:22:53,504 DEBUG [c.c.r.ResourceManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Dispatching resource
state event CREATE_HOST_VO_FOR_CONNECTED to NiciraNvp
2024-12-13 14:22:53,504 DEBUG [c.c.r.ResourceManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Dispatching resource
state event CREATE_HOST_VO_FOR_CONNECTED to BrocadeVcsElement
2024-12-13 14:22:53,504 DEBUG [c.c.r.ResourceManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Dispatching resource
state event CREATE_HOST_VO_FOR_CONNECTED to Ovm3Discoverer
2024-12-13 14:22:53,504 DEBUG [c.c.h.o.r.Ovm3Discoverer]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722)
createHostVOForConnectedAgent: Host
{"id":155,"name":"NODE77","type":"Routing","uuid":"97987917-b74a-4801-855e-ccb6f8bc9c77"}
2024-12-13 14:22:53,504 DEBUG [c.c.r.ResourceManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Dispatching resource
state event CREATE_HOST_VO_FOR_CONNECTED to LxcServerDiscoverer
2024-12-13 14:22:53,504 DEBUG [c.c.r.ResourceManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Dispatching resource
state event CREATE_HOST_VO_FOR_CONNECTED to NetworkUsageManagerImpl
2024-12-13 14:22:53,504 DEBUG [c.c.r.ResourceManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Dispatching resource
state event CREATE_HOST_VO_FOR_CONNECTED to PremiumSecondaryStorageManagerImpl
2024-12-13 14:22:53,504 DEBUG [c.c.r.ResourceManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Dispatching resource
state event CREATE_HOST_VO_FOR_CONNECTED to Ovs
2024-12-13 14:22:53,504 DEBUG [c.c.r.ResourceManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Dispatching resource
state event CREATE_HOST_VO_FOR_CONNECTED to VmwareServerDiscoverer
2024-12-13 14:22:53,504 DEBUG [c.c.r.ResourceManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Dispatching resource
state event CREATE_HOST_VO_FOR_CONNECTED to ConsoleProxyManagerImpl
2024-12-13 14:22:53,504 DEBUG [c.c.r.ResourceManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Dispatching resource
state event CREATE_HOST_VO_FOR_CONNECTED to OvmDiscoverer
2024-12-13 14:22:53,504 DEBUG [c.c.r.ResourceManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Dispatching resource
state event CREATE_HOST_VO_FOR_CONNECTED to KvmServerDiscoverer
2024-12-13 14:22:53,571 DEBUG [c.c.r.ResourceState]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Resource state update:
[id = 155; name = NODE77; old state = Enabled; event = InternalCreated; new
state = Enabled]
2024-12-13 14:22:53,571 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Transition:[Resource
state = Enabled, Agent event = AgentConnected, Host id = 155, name = NODE77]
2024-12-13 14:22:53,608 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Agent's management
server host list is not up to date, sending list update:[172.xx.xx.12,
172.xx.xx.11, 172.xx.xx.10]
2024-12-13 14:22:53,609 DEBUG [c.c.a.m.ClusteredAgentManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) create
ClusteredAgentAttache for 155
2024-12-13 14:22:53,611 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Sending Connect to
listener: XcpServerDiscoverer
2024-12-13 14:22:53,611 DEBUG [c.c.h.x.d.XcpServerDiscoverer]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Not XenServer so moving
on.
2024-12-13 14:22:53,611 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Sending Connect to
listener: HypervServerDiscoverer
2024-12-13 14:22:53,611 DEBUG [c.c.h.h.d.HypervServerDiscoverer]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Not Hyper-V hypervisor,
so moving on.
2024-12-13 14:22:53,611 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Sending Connect to
listener: TungstenElement
2024-12-13 14:22:53,614 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Sending Connect to
listener: DeploymentPlanningManagerImpl
2024-12-13 14:22:53,616 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Sending Connect to
listener: SecurityGroupListener
2024-12-13 14:22:53,616 INFO [c.c.n.s.SecurityGroupListener]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Received a host startup
notification
2024-12-13 14:22:53,618 DEBUG [c.c.a.t.Request]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Seq
155-1615384891342454785: Sending { Cmd , MgmtId: 73209801370656, via:
155(NODE77), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.CleanupNetworkRulesCmd":{"interval":"2076","wait":"0","bypassHostMaintenance":"false"}}]
}
2024-12-13 14:22:53,619 INFO [c.c.n.s.SecurityGroupListener]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Scheduled network rules
cleanup, interval=2076
2024-12-13 14:22:53,619 INFO [c.c.n.s.SecurityGroupListener]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Received a host startup
notification
2024-12-13 14:22:53,619 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Sending Connect to
listener: VmwareManagerImpl
2024-12-13 14:22:53,619 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Sending Connect to
listener: ClusteredVirtualMachineManagerImpl
2024-12-13 14:22:53,619 DEBUG [c.c.v.VirtualMachineManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Received startup
command from hypervisor host. host id: 155
2024-12-13 14:22:53,619 INFO [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Reset VM power state
sync for host: 155
2024-12-13 14:22:53,623 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Sending Connect to
listener: StoragePoolMonitor
2024-12-13 14:22:53,644 DEBUG [c.c.s.l.StoragePoolMonitor]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Host 155 connected,
connecting host to shared pool id 33 and sending storage pool information ...
2024-12-13 14:22:53,646 DEBUG [c.c.s.StorageManagerImpl]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Adding pool Ceph
Storage to host 155
2024-12-13 14:22:53,648 DEBUG [o.a.c.s.d.p.DefaultHostListener]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Sending modify storage
pool command to agent: 155 for storage pool: 33 with timeout 300 seconds
2024-12-13 14:22:53,655 DEBUG [c.c.a.t.Request]
(AgentConnectTaskPool-34:ctx-98bb3aca) (logid:1e0d0722) Seq
155-1615384891342454786: Sending { Cmd , MgmtId: 73209801370656, via:
155(NODE77), Ver: v1, Flags: 100011,
[{"com.cloud.agent.api.ModifyStoragePoolCommand":{"add":"true","pool":{"id":"33","uuid":"c56c2378-288e-37ef-8549-ac569f7ab3b8","host":"172.xx.xx.35,172.xx.xx.36,172.xx.xx.37","path":"cloudstack_RO","port":"0","type":"RBD"},"localPath":"/mnt//61b0126b-2e47-3ad5-b9c4-af4a8f0c199f","wait":"300","bypassHostMaintenance":"false"}}]
}
2024-12-13 14:22:53,679 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-5:null) (logid:) Ping from Routing host 155(NODE77)
2024-12-13 14:22:53,679 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-5:null) (logid:) Process host VM state report from ping
process. host: 155
2024-12-13 14:22:53,679 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-5:null) (logid:) Process VM state report. host: 155,
number of records in report: 0
2024-12-13 14:22:53,684 DEBUG [c.c.v.VirtualMachinePowerStateSyncImpl]
(AgentManager-Handler-5:null) (logid:) Done with process of VM state report.
host: 155
2024-12-13 14:22:53,692 INFO [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-5:null) (logid:) PingMap for agent: 155 will not be
updated because agent is no longer in the PingMap
2024-12-13 14:22:53,695 DEBUG [c.c.a.m.AgentManagerImpl]
(AgentManager-Handler-5:null) (logid:) Not processing PingRoutingCommand for
agent id=0; can't find the host in the DB
```
And this is the agent log:
```
2024-12-13 14:21:38,287 INFO [cloud.agent.AgentShell] (main:null) (logid:)
Implementation Version is 4.19.1.3
2024-12-13 14:21:38,289 INFO [cloud.agent.AgentShell] (main:null) (logid:)
agent.properties found at /etc/cloudstack/agent/agent.properties
2024-12-13 14:21:38,342 INFO [cloud.agent.AgentShell] (main:null) (logid:)
Defaulting to using properties file for storage
2024-12-13 14:21:38,344 INFO [cloud.agent.AgentShell] (main:null) (logid:)
Defaulting to the constant time backoff algorithm
2024-12-13 14:21:38,405 INFO [cloud.utils.LogUtils] (main:null) (logid:)
log4j configuration found at /etc/cloudstack/agent/log4j-cloud.xml
2024-12-13 14:21:38,405 INFO [cloud.agent.AgentShell] (main:null) (logid:)
Using default Java settings for IPv6 preference for agent connection
2024-12-13 14:21:38,504 INFO [cloud.agent.Agent] (main:null) (logid:) id is
2024-12-13 14:21:38,522 ERROR [kvm.resource.LibvirtComputingResource]
(main:null) (logid:) uefi properties file not found due to: Unable to find file
uefi.properties.
2024-12-13 14:21:38,586 INFO [kvm.resource.LibvirtConnection] (main:null)
(logid:) No existing libvirtd connection found. Opening a new one
2024-12-13 14:21:38,984 INFO [kvm.resource.LibvirtComputingResource]
(main:null) (logid:) IO uring driver for Qemu: enabled
2024-12-13 14:21:39,108 INFO [kvm.storage.KVMStoragePoolManager]
(main:null) (logid:) adding storage adaptor for
com.cloud.hypervisor.kvm.storage.LinstorStorageAdaptor
2024-12-13 14:21:39,118 INFO [kvm.storage.KVMStoragePoolManager]
(main:null) (logid:) adding storage adaptor for
com.cloud.hypervisor.kvm.storage.StorPoolStorageAdaptor
2024-12-13 14:21:39,119 WARN [kvm.storage.KVMStoragePoolManager]
(main:null) (logid:) Duplicate StorageAdaptor type PowerFlex, not loading
com.cloud.hypervisor.kvm.storage.ScaleIOStorageAdaptor
2024-12-13 14:21:39,119 INFO [kvm.storage.KVMStoragePoolManager]
(main:null) (logid:) adding storage adaptor for
com.cloud.hypervisor.kvm.storage.IscsiAdmStorageAdaptor
2024-12-13 14:21:39,120 INFO [kvm.storage.KVMStoragePoolManager]
(main:null) (logid:) adding storage adaptor for
com.cloud.hypervisor.kvm.storage.FiberChannelAdapter
2024-12-13 14:21:39,129 INFO [kvm.storage.FiberChannelAdapter] (main:null)
(logid:) Loaded FiberChannelAdapter for StorageLayer
2024-12-13 14:21:39,133 INFO [kvm.storage.FiberChannelAdapter] (main:null)
(logid:) Loaded FiberChannelAdapter for StorageLayer on host [NODE77]
2024-12-13 14:21:39,134 INFO [kvm.resource.LibvirtComputingResource]
(main:null) (logid:) No libvirt.vif.driver specified. Defaults to
BridgeVifDriver.
2024-12-13 14:21:39,381 INFO [cloud.serializer.GsonHelper] (main:null)
(logid:) Default Builder inited.
2024-12-13 14:21:39,382 INFO [kvm.resource.LibvirtComputingResource]
(main:null) (logid:) iscsi session clean up is disabled
2024-12-13 14:21:39,385 INFO [kvm.resource.LibvirtComputingResource]
(main:null) (logid:) Skipping the memory balloon stats period setting, since
there are no VMs (active Libvirt domains) on this host.
2024-12-13 14:21:39,386 INFO [kvm.resource.LibvirtComputingResource]
(main:null) (logid:) The [vm.memballoon.stats.period] property is set to '0',
this prevents memory statistics from being displayed correctly. Adjust
(increase) the value of this parameter to correct this.
2024-12-13 14:21:39,401 INFO [cloud.agent.Agent] (main:null) (logid:) Agent
[id = new : type = LibvirtComputingResource : zone = 12 : pod = 15 : workers =
5 : host = 172.xx.xx.12 : port = 8250
2024-12-13 14:21:39,412 INFO [utils.nio.NioClient] (main:null) (logid:)
Connecting to 172.xx.xx.12:8250
2024-12-13 14:21:39,445 INFO [utils.nio.Link] (main:null) (logid:) Conf
file found: /etc/cloudstack/agent/agent.properties
2024-12-13 14:21:39,906 INFO [utils.nio.NioClient] (main:null) (logid:)
SSL: Handshake done
2024-12-13 14:21:39,907 INFO [utils.nio.NioClient] (main:null) (logid:)
Connected to 172.xx.xx.12:8250
2024-12-13 14:21:39,978 INFO [utils.linux.KVMHostInfo]
(Agent-Handler-1:null) (logid:) Fetching CPU speed from command "lscpu".
2024-12-13 14:21:40,059 ERROR [utils.linux.KVMHostInfo]
(Agent-Handler-1:null) (logid:) Unable to retrieve the CPU speed from lscpu.
java.lang.NullPointerException
at
java.base/jdk.internal.math.FloatingDecimal.readJavaFormatString(FloatingDecimal.java:1838)
at
java.base/jdk.internal.math.FloatingDecimal.parseFloat(FloatingDecimal.java:122)
at java.base/java.lang.Float.parseFloat(Float.java:455)
at
org.apache.cloudstack.utils.linux.KVMHostInfo.getCpuSpeedFromCommandLscpu(KVMHostInfo.java:134)
at
org.apache.cloudstack.utils.linux.KVMHostInfo.getCpuSpeed(KVMHostInfo.java:109)
at
org.apache.cloudstack.utils.linux.KVMHostInfo.getHostInfoFromLibvirt(KVMHostInfo.java:189)
at
org.apache.cloudstack.utils.linux.KVMHostInfo.<init>(KVMHostInfo.java:66)
at
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.initialize(LibvirtComputingResource.java:3627)
at com.cloud.agent.Agent.sendStartup(Agent.java:460)
at com.cloud.agent.Agent$ServerHandler.doTask(Agent.java:1125)
at com.cloud.utils.nio.Task.call(Task.java:83)
at com.cloud.utils.nio.Task.call(Task.java:29)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)
2024-12-13 14:21:40,062 INFO [utils.linux.KVMHostInfo]
(Agent-Handler-1:null) (logid:) Fetching CPU speed from file
[/sys/devices/system/cpu/cpu0/cpufreq/base_frequency].
2024-12-13 14:21:40,063 ERROR [utils.linux.KVMHostInfo]
(Agent-Handler-1:null) (logid:) Unable to retrieve the CPU speed from file
[/sys/devices/system/cpu/cpu0/cpufreq/base_frequency]
java.io.FileNotFoundException:
/sys/devices/system/cpu/cpu0/cpufreq/base_frequency (No such file or directory)
at java.base/java.io.FileInputStream.open0(Native Method)
at java.base/java.io.FileInputStream.open(FileInputStream.java:219)
at java.base/java.io.FileInputStream.<init>(FileInputStream.java:157)
at java.base/java.io.FileInputStream.<init>(FileInputStream.java:112)
at java.base/java.io.FileReader.<init>(FileReader.java:60)
at
org.apache.cloudstack.utils.linux.KVMHostInfo.getCpuSpeedFromFile(KVMHostInfo.java:145)
at
org.apache.cloudstack.utils.linux.KVMHostInfo.getCpuSpeed(KVMHostInfo.java:114)
at
org.apache.cloudstack.utils.linux.KVMHostInfo.getHostInfoFromLibvirt(KVMHostInfo.java:189)
at
org.apache.cloudstack.utils.linux.KVMHostInfo.<init>(KVMHostInfo.java:66)
at
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.initialize(LibvirtComputingResource.java:3627)
at com.cloud.agent.Agent.sendStartup(Agent.java:460)
at com.cloud.agent.Agent$ServerHandler.doTask(Agent.java:1125)
at com.cloud.utils.nio.Task.call(Task.java:83)
at com.cloud.utils.nio.Task.call(Task.java:29)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)
2024-12-13 14:21:40,063 INFO [utils.linux.KVMHostInfo]
(Agent-Handler-1:null) (logid:) Fetching CPU speed from "host capabilities"
2024-12-13 14:21:40,075 INFO [utils.linux.KVMHostInfo]
(Agent-Handler-1:null) (logid:) Retrieved value [1996249000] from "host
capabilities". This corresponds to a CPU speed of [1996] MHz.
2024-12-13 14:21:40,089 INFO [kvm.resource.LibvirtComputingResource]
(Agent-Handler-1:null) (logid:) Host uses control group [cgroup2fs].
2024-12-13 14:21:40,089 INFO [kvm.resource.LibvirtComputingResource]
(Agent-Handler-1:null) (logid:) Calculating the max shares of the host.
2024-12-13 14:21:40,089 INFO [kvm.resource.LibvirtComputingResource]
(Agent-Handler-1:null) (logid:) The max shares of the host is [255488].
2024-12-13 14:21:40,179 WARN [kvm.resource.LibvirtComputingResource]
(Agent-Handler-1:null) (logid:) Execution of process [9009] for command [sudo
grep InitiatorName= /etc/iscsi/initiatorname.iscsi ] failed.
2024-12-13 14:21:40,180 WARN [kvm.resource.LibvirtComputingResource]
(Agent-Handler-1:null) (logid:) Process [9009] for command [sudo grep
InitiatorName= /etc/iscsi/initiatorname.iscsi ] encountered the error: [grep:
/etc/iscsi/initiatorname.iscsi: No such file or directory].
2024-12-13 14:21:40,209 WARN [utils.script.Script] (Agent-Handler-1:null)
(logid:) Execution of process [9021] for command [/bin/bash -c virt-v2v
--version ] failed.
2024-12-13 14:21:40,210 WARN [utils.script.Script] (Agent-Handler-1:null)
(logid:) Process [9021] for command [/bin/bash -c virt-v2v --version ]
encountered the error: [127].
2024-12-13 14:21:40,239 INFO [kvm.storage.LibvirtStorageAdaptor]
(Agent-Handler-1:null) (logid:) Attempting to create storage pool
c925ad9d-7b05-4a6a-97c6-e564cd26257b (Filesystem) in libvirt
2024-12-13 14:21:40,246 WARN [kvm.storage.LibvirtStorageAdaptor]
(Agent-Handler-1:null) (logid:) Storage pool
c925ad9d-7b05-4a6a-97c6-e564cd26257b was not found running in libvirt. Need to
create it.
2024-12-13 14:21:40,247 INFO [kvm.storage.LibvirtStorageAdaptor]
(Agent-Handler-1:null) (logid:) Didn't find an existing storage pool
c925ad9d-7b05-4a6a-97c6-e564cd26257b by UUID, checking for pools with duplicate
paths
2024-12-13 14:21:40,270 INFO [kvm.storage.LibvirtStorageAdaptor]
(Agent-Handler-1:null) (logid:) Trying to fetch storage pool
c925ad9d-7b05-4a6a-97c6-e564cd26257b from libvirt
2024-12-13 14:21:40,420 INFO [cloud.agent.Agent] (Agent-Handler-2:null)
(logid:) Process agent startup answer, agent id = 0
2024-12-13 14:21:40,421 INFO [cloud.agent.Agent] (Agent-Handler-2:null)
(logid:) Set agent id 0
2024-12-13 14:21:40,435 INFO [cloud.agent.Agent] (Agent-Handler-2:null)
(logid:) Startup Response Received: agent id = 0
2024-12-13 14:21:40,664 INFO [kvm.storage.LibvirtStorageAdaptor]
(agentRequest-Handler-3:null) (logid:60a026ea) Attempting to create storage
pool c56c2378-288e-37ef-8549-ac569f7ab3b8 (RBD) in libvirt
2024-12-13 14:21:40,667 WARN [kvm.storage.LibvirtStorageAdaptor]
(agentRequest-Handler-3:null) (logid:60a026ea) Storage pool
c56c2378-288e-37ef-8549-ac569f7ab3b8 was not found running in libvirt. Need to
create it.
2024-12-13 14:21:40,667 INFO [kvm.storage.LibvirtStorageAdaptor]
(agentRequest-Handler-3:null) (logid:60a026ea) Didn't find an existing storage
pool c56c2378-288e-37ef-8549-ac569f7ab3b8 by UUID, checking for pools with
duplicate paths
2024-12-13 14:22:11,225 ERROR [kvm.storage.LibvirtStorageAdaptor]
(agentRequest-Handler-3:null) (logid:60a026ea) Failed to create RBD storage
pool: org.libvirt.LibvirtException: Unable to list RBD images: No such file or
directory
2024-12-13 14:22:11,226 ERROR [kvm.storage.LibvirtStorageAdaptor]
(agentRequest-Handler-3:null) (logid:60a026ea) Failed to create the RBD storage
pool, cleaning up the libvirt secret
2024-12-13 14:22:11,228 WARN [cloud.agent.Agent]
(agentRequest-Handler-3:null) (logid:60a026ea) Caught:
com.cloud.utils.exception.CloudRuntimeException: Failed to create storage
pool: c56c2378-288e-37ef-8549-ac569f7ab3b8
at
com.cloud.hypervisor.kvm.storage.LibvirtStorageAdaptor.createStoragePool(LibvirtStorageAdaptor.java:743)
at
com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.createStoragePool(KVMStoragePoolManager.java:364)
at
com.cloud.hypervisor.kvm.storage.KVMStoragePoolManager.createStoragePool(KVMStoragePoolManager.java:358)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtModifyStoragePoolCommandWrapper.execute(LibvirtModifyStoragePoolCommandWrapper.java:42)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtModifyStoragePoolCommandWrapper.execute(LibvirtModifyStoragePoolCommandWrapper.java:35)
at
com.cloud.hypervisor.kvm.resource.wrapper.LibvirtRequestWrapper.execute(LibvirtRequestWrapper.java:78)
at
com.cloud.hypervisor.kvm.resource.LibvirtComputingResource.executeRequest(LibvirtComputingResource.java:1929)
at com.cloud.agent.Agent.processRequest(Agent.java:683)
at com.cloud.agent.Agent$AgentRequestHandler.doTask(Agent.java:1106)
at com.cloud.utils.nio.Task.call(Task.java:83)
at com.cloud.utils.nio.Task.call(Task.java:29)
at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
at
java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
at
java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
at java.base/java.lang.Thread.run(Thread.java:829)
2024-12-13 14:22:16,317 INFO [cloud.agent.Agent] (Agent-Handler-2:null)
(logid:) Lost connection to host: 172.xx.xx.12. Attempting reconnection while
we still have 0 commands in progress.
2024-12-13 14:22:16,318 INFO [utils.nio.NioClient] (Agent-Handler-2:null)
(logid:) NioClient connection closed
```
--
This is an automated message from the Apache Git Service.
To respond to the message, please log on to GitHub and use the
URL above to go to the specific comment.
To unsubscribe, e-mail: commits-unsubscr...@cloudstack.apache.org
For queries about this service, please contact Infrastructure at:
us...@infra.apache.org
