Skip to content

Commit

Permalink
Add logs to LibvirtComputingResource's metrics collection process (#…
Browse files Browse the repository at this point in the history
…8511)

* Add logs to LibvirtComputingResource's metrics collecting process

* Apply Joao's suggestions

Co-authored-by: João Jandre <[email protected]>

* Adjust some logs

* Print memory statistics log in one line

---------

Co-authored-by: João Jandre <[email protected]>
  • Loading branch information
winterhazel and JoaoJandre committed Sep 6, 2024
1 parent 82f113b commit b11897c
Show file tree
Hide file tree
Showing 3 changed files with 380 additions and 181 deletions.
Original file line number Diff line number Diff line change
Expand Up @@ -44,6 +44,8 @@
import java.util.concurrent.ConcurrentHashMap;
import java.util.regex.Matcher;
import java.util.regex.Pattern;
import java.util.stream.Collectors;
import java.util.stream.Stream;

import javax.naming.ConfigurationException;
import javax.xml.parsers.DocumentBuilder;
Expand Down Expand Up @@ -76,6 +78,8 @@
import org.apache.commons.lang.math.NumberUtils;
import org.apache.commons.lang3.ObjectUtils;
import org.apache.commons.lang3.StringUtils;
import org.apache.commons.lang3.builder.ReflectionToStringBuilder;
import org.apache.commons.lang3.builder.ToStringStyle;
import org.apache.logging.log4j.Logger;
import org.apache.logging.log4j.LogManager;
import org.apache.xerces.impl.xpath.regex.Match;
Expand Down Expand Up @@ -446,7 +450,7 @@ public class LibvirtComputingResource extends ServerResourceBase implements Serv
protected WatchDogModel watchDogModel = WatchDogModel.I6300ESB;

private final Map <String, String> pifs = new HashMap<String, String>();
private final Map<String, VmStats> vmStats = new ConcurrentHashMap<String, VmStats>();
private final Map<String, LibvirtExtendedVmStatsEntry> vmStats = new ConcurrentHashMap<>();

private final Map<String, DomainBlockStats> vmDiskStats = new ConcurrentHashMap<>();

Expand Down Expand Up @@ -2346,7 +2350,7 @@ public PowerState getVmState(final Connect conn, final String vmName) {
final PowerState s = convertToPowerState(vms.getInfo().state);
return s;
} catch (final LibvirtException e) {
LOGGER.warn("Can't get vm state " + vmName + e.getMessage() + "retry:" + retry);
LOGGER.error("Could not get state for VM [{}] (retry={}) due to:", vmName, retry, e);
} finally {
try {
if (vms != null) {
Expand Down Expand Up @@ -4414,127 +4418,189 @@ protected String getDiskPathFromDiskDef(DiskDef disk) {
return null;
}

private class VmStats {
long usedTime;
long tx;
long rx;
long ioRead;
long ioWrote;
long bytesRead;
long bytesWrote;
Calendar timestamp;
private String vmToString(Domain dm) throws LibvirtException {
return String.format("{\"name\":\"%s\",\"uuid\":\"%s\"}", dm.getName(), dm.getUUIDString());
}

/**
* Returns metrics for the period since this function was last called for the specified VM.
* @param conn the Libvirt connection.
* @param vmName name of the VM.
* @return metrics for the period since last time this function was called for the VM.
* @throws LibvirtException
*/
public VmStatsEntry getVmStat(final Connect conn, final String vmName) throws LibvirtException {
Domain dm = null;
try {
LOGGER.debug("Trying to get VM with name [{}].", vmName);
dm = getDomain(conn, vmName);
if (dm == null) {
LOGGER.warn("Could not get VM with name [{}].", vmName);
return null;
}
DomainInfo info = dm.getInfo();
final VmStatsEntry stats = new VmStatsEntry();

stats.setNumCPUs(info.nrVirtCpu);
stats.setEntityType("vm");
LibvirtExtendedVmStatsEntry newStats = getVmCurrentStats(dm);
LibvirtExtendedVmStatsEntry oldStats = vmStats.get(vmName);

stats.setMemoryKBs(info.maxMem);
stats.setTargetMemoryKBs(info.memory);
stats.setIntFreeMemoryKBs(getMemoryFreeInKBs(dm));
VmStatsEntry metrics = calculateVmMetrics(dm, oldStats, newStats);
vmStats.put(vmName, newStats);

/* get cpu utilization */
VmStats oldStats = null;
return metrics;
} finally {
if (dm != null) {
dm.free();
}
}
}

final Calendar now = Calendar.getInstance();
/**
* Returns a VM's current statistics.
* @param dm domain of the VM.
* @return current statistics of the VM.
* @throws LibvirtException
*/
protected LibvirtExtendedVmStatsEntry getVmCurrentStats(final Domain dm) throws LibvirtException {
final LibvirtExtendedVmStatsEntry stats = new LibvirtExtendedVmStatsEntry();

oldStats = vmStats.get(vmName);
getVmCurrentCpuStats(dm, stats);
getVmCurrentNetworkStats(dm, stats);
getVmCurrentDiskStats(dm, stats);

long elapsedTime = 0;
if (oldStats != null) {
elapsedTime = now.getTimeInMillis() - oldStats.timestamp.getTimeInMillis();
double utilization = (info.cpuTime - oldStats.usedTime) / ((double)elapsedTime * 1000000);
LOGGER.debug("Retrieved statistics for VM [{}]: [{}].", vmToString(dm), stats);
stats.setTimestamp(Calendar.getInstance());
return stats;
}

utilization = utilization / info.nrVirtCpu;
if (utilization > 0) {
stats.setCPUUtilization(utilization * 100);
}
}
/**
* Passes a VM's current CPU statistics into the provided LibvirtExtendedVmStatsEntry.
* @param dm domain of the VM.
* @param stats LibvirtExtendedVmStatsEntry that will receive the current CPU statistics.
* @throws LibvirtException
*/
protected void getVmCurrentCpuStats(final Domain dm, final LibvirtExtendedVmStatsEntry stats) throws LibvirtException {
LOGGER.trace("Getting CPU stats for VM [{}].", vmToString(dm));
stats.setCpuTime(dm.getInfo().cpuTime);
}

/* get network stats */
/**
* Passes a VM's current network statistics into the provided LibvirtExtendedVmStatsEntry.
* @param dm domain of the VM.
* @param stats LibvirtExtendedVmStatsEntry that will receive the current network statistics.
* @throws LibvirtException
*/
protected void getVmCurrentNetworkStats(final Domain dm, final LibvirtExtendedVmStatsEntry stats) throws LibvirtException {
final String vmAsString = vmToString(dm);
LOGGER.trace("Getting network stats for VM [{}].", vmAsString);
final List<InterfaceDef> vifs = getInterfaces(dm.getConnect(), dm.getName());
LOGGER.debug("Found [{}] network interface(s) for VM [{}].", vifs.size(), vmAsString);
double rx = 0;
double tx = 0;
for (final InterfaceDef vif : vifs) {
final DomainInterfaceStats ifStats = dm.interfaceStats(vif.getDevName());
rx += ifStats.rx_bytes;
tx += ifStats.tx_bytes;
}
stats.setNetworkReadKBs(rx / 1024);
stats.setNetworkWriteKBs(tx / 1024);
}

final List<InterfaceDef> vifs = getInterfaces(conn, vmName);
long rx = 0;
long tx = 0;
for (final InterfaceDef vif : vifs) {
final DomainInterfaceStats ifStats = dm.interfaceStats(vif.getDevName());
rx += ifStats.rx_bytes;
tx += ifStats.tx_bytes;
/**
* Passes a VM's current disk statistics into the provided LibvirtExtendedVmStatsEntry.
* @param dm domain of the VM.
* @param stats LibvirtExtendedVmStatsEntry that will receive the current disk statistics.
* @throws LibvirtException
*/
protected void getVmCurrentDiskStats(final Domain dm, final LibvirtExtendedVmStatsEntry stats) throws LibvirtException {
final String vmAsString = vmToString(dm);
LOGGER.trace("Getting disk stats for VM [{}].", vmAsString);
final List<DiskDef> disks = getDisks(dm.getConnect(), dm.getName());
LOGGER.debug("Found [{}] disk(s) for VM [{}].", disks.size(), vmAsString);
long io_rd = 0;
long io_wr = 0;
double bytes_rd = 0;
double bytes_wr = 0;
for (final DiskDef disk : disks) {
if (disk.getDeviceType() == DeviceType.CDROM || disk.getDeviceType() == DeviceType.FLOPPY) {
LOGGER.debug("Ignoring disk [{}] in VM [{}]'s stats since its deviceType is [{}].", disk.toString().replace("\n", ""), vmAsString, disk.getDeviceType());
continue;
}
final DomainBlockStats blockStats = dm.blockStats(disk.getDiskLabel());
io_rd += blockStats.rd_req;
io_wr += blockStats.wr_req;
bytes_rd += blockStats.rd_bytes;
bytes_wr += blockStats.wr_bytes;
}
stats.setDiskReadIOs(io_rd);
stats.setDiskWriteIOs(io_wr);
stats.setDiskReadKBs(bytes_rd / 1024);
stats.setDiskWriteKBs(bytes_wr / 1024);
}

if (oldStats != null) {
final double deltarx = rx - oldStats.rx;
if (deltarx > 0) {
stats.setNetworkReadKBs(deltarx / 1024);
}
final double deltatx = tx - oldStats.tx;
if (deltatx > 0) {
stats.setNetworkWriteKBs(deltatx / 1024);
}
/**
* Calculates a VM's metrics for the period between the two statistics given as parameters.
* @param dm domain of the VM.
* @param oldStats old statistics. If null, the CPU, network and disk utilization won't be calculated.
* @param newStats new statistics.
* @return metrics for the period between the two statistics.
* @throws LibvirtException
*/
protected VmStatsEntry calculateVmMetrics(final Domain dm, final LibvirtExtendedVmStatsEntry oldStats, final LibvirtExtendedVmStatsEntry newStats) throws LibvirtException {
final VmStatsEntry metrics = new VmStatsEntry();
final DomainInfo info = dm.getInfo();
final String vmAsString = vmToString(dm);

metrics.setEntityType("vm");
LOGGER.trace("Writing VM [{}]'s CPU and memory information into the metrics.", vmAsString);
metrics.setNumCPUs(info.nrVirtCpu);
metrics.setMemoryKBs(info.maxMem);
metrics.setTargetMemoryKBs(info.memory);
LOGGER.trace("Trying to get free memory for VM [{}].", vmAsString);
metrics.setIntFreeMemoryKBs(getMemoryFreeInKBs(dm));

if (oldStats != null) {
LOGGER.debug("Old stats exist for VM [{}]; therefore, the utilization will be calculated.", vmAsString);

LOGGER.trace("Calculating CPU utilization for VM [{}].", vmAsString);
final Calendar now = Calendar.getInstance();
long elapsedTime = now.getTimeInMillis() - oldStats.getTimestamp().getTimeInMillis();
double utilization = (info.cpuTime - oldStats.getCpuTime()) / ((double) elapsedTime * 1000000 * info.nrVirtCpu);
if (utilization > 0) {
metrics.setCPUUtilization(utilization * 100);
}

/* get disk stats */
final List<DiskDef> disks = getDisks(conn, vmName);
long io_rd = 0;
long io_wr = 0;
long bytes_rd = 0;
long bytes_wr = 0;
for (final DiskDef disk : disks) {
if (disk.getDeviceType() == DeviceType.CDROM || disk.getDeviceType() == DeviceType.FLOPPY) {
continue;
}
final DomainBlockStats blockStats = dm.blockStats(disk.getDiskLabel());
io_rd += blockStats.rd_req;
io_wr += blockStats.wr_req;
bytes_rd += blockStats.rd_bytes;
bytes_wr += blockStats.wr_bytes;
LOGGER.trace("Calculating network utilization for VM [{}].", vmAsString);
final double deltarx = newStats.getNetworkReadKBs() - oldStats.getNetworkReadKBs();
if (deltarx > 0) {
metrics.setNetworkReadKBs(deltarx);
}

if (oldStats != null) {
final long deltaiord = io_rd - oldStats.ioRead;
if (deltaiord > 0) {
stats.setDiskReadIOs(deltaiord);
}
final long deltaiowr = io_wr - oldStats.ioWrote;
if (deltaiowr > 0) {
stats.setDiskWriteIOs(deltaiowr);
}
final double deltabytesrd = bytes_rd - oldStats.bytesRead;
if (deltabytesrd > 0) {
stats.setDiskReadKBs(deltabytesrd / 1024);
}
final double deltabyteswr = bytes_wr - oldStats.bytesWrote;
if (deltabyteswr > 0) {
stats.setDiskWriteKBs(deltabyteswr / 1024);
}
final double deltatx = newStats.getNetworkWriteKBs() - oldStats.getNetworkWriteKBs();
if (deltatx > 0) {
metrics.setNetworkWriteKBs(deltatx);
}

/* save to Hashmap */
final VmStats newStat = new VmStats();
newStat.usedTime = info.cpuTime;
newStat.rx = rx;
newStat.tx = tx;
newStat.ioRead = io_rd;
newStat.ioWrote = io_wr;
newStat.bytesRead = bytes_rd;
newStat.bytesWrote = bytes_wr;
newStat.timestamp = now;
vmStats.put(vmName, newStat);
return stats;
} finally {
if (dm != null) {
dm.free();
LOGGER.trace("Calculating disk utilization for VM [{}].", vmAsString);
final double deltaiord = newStats.getDiskReadIOs() - oldStats.getDiskReadIOs();
if (deltaiord > 0) {
metrics.setDiskReadIOs(deltaiord);
}
final double deltaiowr = newStats.getDiskWriteIOs() - oldStats.getDiskWriteIOs();
if (deltaiowr > 0) {
metrics.setDiskWriteIOs(deltaiowr);
}
final double deltabytesrd = newStats.getDiskReadKBs() - oldStats.getDiskReadKBs();
if (deltabytesrd > 0) {
metrics.setDiskReadKBs(deltabytesrd);
}
final double deltabyteswr = newStats.getDiskWriteKBs() - oldStats.getDiskWriteKBs();
if (deltabyteswr > 0) {
metrics.setDiskWriteKBs(deltabyteswr);
}
}

String metricsAsString = new ReflectionToStringBuilder(metrics, ToStringStyle.JSON_STYLE).setExcludeFieldNames("vmId", "vmUuid").toString();
LOGGER.debug("Calculated metrics for VM [{}]: [{}].", vmAsString, metricsAsString);

return metrics;
}

/**
Expand All @@ -4546,10 +4612,8 @@ public VmStatsEntry getVmStat(final Connect conn, final String vmName) throws Li
*/
protected long getMemoryFreeInKBs(Domain dm) throws LibvirtException {
MemoryStatistic[] memoryStats = dm.memoryStats(NUMMEMSTATS);

if(LOGGER.isTraceEnabled()){
LOGGER.trace(String.format("Retrieved memory statistics (information about tags can be found on the libvirt documentation):", ArrayUtils.toString(memoryStats)));
}
LOGGER.trace("Retrieved memory statistics (information about tags can be found on the libvirt documentation): {}.",
() -> Stream.of(memoryStats).map(stat -> stat.toString().trim().replace("\n", ",")).collect(Collectors.joining("},{", "[{", "}]")));

long freeMemory = NumberUtils.LONG_MINUS_ONE;

Expand Down
Original file line number Diff line number Diff line change
@@ -0,0 +1,51 @@
// Licensed to the Apache Software Foundation (ASF) under one
// or more contributor license agreements. See the NOTICE file
// distributed with this work for additional information
// regarding copyright ownership. The ASF licenses this file
// to you under the Apache License, Version 2.0 (the
// "License"); you may not use this file except in compliance
// with the License. You may obtain a copy of the License at
//
// http://www.apache.org/licenses/LICENSE-2.0
//
// Unless required by applicable law or agreed to in writing,
// software distributed under the License is distributed on an
// "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
// KIND, either express or implied. See the License for the
// specific language governing permissions and limitations
// under the License.
package com.cloud.hypervisor.kvm.resource;

import com.cloud.agent.api.VmStatsEntry;
import org.apache.cloudstack.utils.reflectiontostringbuilderutils.ReflectionToStringBuilderUtils;

import java.util.Calendar;

public class LibvirtExtendedVmStatsEntry extends VmStatsEntry {
private long cpuTime;
private Calendar timestamp;

public LibvirtExtendedVmStatsEntry() {
}

public long getCpuTime() {
return cpuTime;
}

public void setCpuTime(long cpuTime) {
this.cpuTime = cpuTime;
}

public Calendar getTimestamp() {
return timestamp;
}

public void setTimestamp(Calendar timestamp) {
this.timestamp = timestamp;
}

@Override
public String toString() {
return ReflectionToStringBuilderUtils.reflectOnlySelectedFields(this, "cpuTime", "networkWriteKBs", "networkReadKBs", "diskReadIOs", "diskWriteIOs", "diskReadKBs", "diskWriteKBs");
}
}
Loading

0 comments on commit b11897c

Please sign in to comment.