Skip to content

Commit

Permalink
Wrap the log level for periodic work
Browse files Browse the repository at this point in the history
  • Loading branch information
@gavinfish
gavinfish committed Dec 14, 2018
1 parent 6b804c2 commit e4e3852
Show file tree
Hide file tree
Showing 3 changed files with 41 additions and 35 deletions.
41 changes: 21 additions & 20 deletions src/main/java/com/microsoft/azure/vmagent/AzureVMAgentCleanUpTask.java
View file
Expand Up @@ -210,7 +210,7 @@ public void cleanDeployments() {
}

public void cleanDeployments(long successTimeoutInMinutes, long failTimeoutInMinutes) {
LOGGER.log(Level.INFO, "AzureVMAgentCleanUpTask: cleanDeployments: Cleaning deployments");
LOGGER.log(getNormalLoggingLevel(), "AzureVMAgentCleanUpTask: cleanDeployments: Cleaning deployments");
// Walk the queue, popping and pushing until we reach an item that we've already
// dealt with or the queue is empty.
DeploymentInfo firstBackInQueue = null;
Expand All @@ -219,7 +219,7 @@ public void cleanDeployments(long successTimeoutInMinutes, long failTimeoutInMin
while (!deploymentsToClean.isEmpty() && firstBackInQueue != deploymentsToClean.peek()) {
DeploymentInfo info = deploymentsToClean.remove();

LOGGER.log(Level.INFO,
LOGGER.log(getNormalLoggingLevel(),
"AzureVMAgentCleanUpTask: cleanDeployments: Checking deployment {0}",
info.getDeploymentName());

Expand All @@ -245,19 +245,19 @@ public void cleanDeployments(long successTimeoutInMinutes, long failTimeoutInMin
deployment = azureClient.deployments().
getByResourceGroup(info.getResourceGroupName(), info.getDeploymentName());
} catch (NullPointerException e) {
LOGGER.log(Level.INFO,
LOGGER.log(getNormalLoggingLevel(),
"AzureVMAgentCleanUpTask: cleanDeployments: Deployment not found, skipping");
continue;
}
if (deployment == null) {
LOGGER.log(Level.INFO,
LOGGER.log(getNormalLoggingLevel(),
"AzureVMAgentCleanUpTask: cleanDeployments: Deployment not found, skipping");
continue;
}

DateTime deploymentTime = deployment.timestamp();

LOGGER.log(Level.INFO,
LOGGER.log(getNormalLoggingLevel(),
"AzureVMAgentCleanUpTask: cleanDeployments: Deployment created on {0}",
deploymentTime.toDate());
long deploymentTimeInMillis = deploymentTime.getMillis();
Expand All @@ -272,7 +272,7 @@ public void cleanDeployments(long successTimeoutInMinutes, long failTimeoutInMin
String state = deployment.provisioningState();

if (!state.equalsIgnoreCase("succeeded") && diffTimeInMinutes > failTimeoutInMinutes) {
LOGGER.log(Level.INFO,
LOGGER.log(getNormalLoggingLevel(),
"AzureVMAgentCleanUpTask: cleanDeployments: "
+ "Failed deployment older than {0} minutes, deleting",
failTimeoutInMinutes);
Expand All @@ -284,7 +284,7 @@ public void cleanDeployments(long successTimeoutInMinutes, long failTimeoutInMin
}
} else if (state.equalsIgnoreCase("succeeded")
&& diffTimeInMinutes > successTimeoutInMinutes) {
LOGGER.log(Level.INFO,
LOGGER.log(getNormalLoggingLevel(),
"AzureVMAgentCleanUpTask: cleanDeployments: "
+ "Successful deployment older than {0} minutes, deleting",
successTimeoutInMinutes);
Expand All @@ -295,7 +295,7 @@ public void cleanDeployments(long successTimeoutInMinutes, long failTimeoutInMin
delegate.removeStorageBlob(new URI(info.scriptUri), info.getResourceGroupName());
}
} else {
LOGGER.log(Level.INFO,
LOGGER.log(getNormalLoggingLevel(),
"AzureVMAgentCleanUpTask: cleanDeployments: Deployment newer than timeout, keeping");

if (firstBackInQueue == null) {
Expand All @@ -305,7 +305,7 @@ public void cleanDeployments(long successTimeoutInMinutes, long failTimeoutInMin
deploymentsToClean.add(info);
}
} catch (Exception e) {
LOGGER.log(Level.INFO,
LOGGER.log(Level.WARNING,
"AzureVMAgentCleanUpTask: cleanDeployments: Failed to get/delete deployment: {0}",
e);
// Check the number of attempts remaining. If greater than 0, decrement
Expand All @@ -324,7 +324,7 @@ public void cleanDeployments(long successTimeoutInMinutes, long failTimeoutInMin
}
DeploymentRegistrar.getInstance().syncDeploymentsToClean();

LOGGER.log(Level.INFO, "AzureVMAgentCleanUpTask: cleanDeployments: Done cleaning deployments");
LOGGER.log(getNormalLoggingLevel(), "AzureVMAgentCleanUpTask: cleanDeployments: Done cleaning deployments");
}

/* There are some edge-cases where we might loose track of the provisioned resources:
Expand Down Expand Up @@ -445,7 +445,7 @@ private int getPriority(GenericResource resource) {
}
}

LOGGER.log(Level.INFO,
LOGGER.log(getNormalLoggingLevel(),
"cleanLeakedResources: deleting {0} from resource group {1}",
new Object[]{resource.name(), resourceGroup});
azureClient.genericResources().deleteById(resource.id());
Expand Down Expand Up @@ -495,15 +495,15 @@ private void cleanVMs(ExecutionEngine executionEngine) {
// Even if offline, a machine that has been temporarily marked offline
// should stay (this could be for investigation).
if (azureComputer.isSetOfflineByUser()) {
LOGGER.log(Level.INFO,
LOGGER.log(getNormalLoggingLevel(),
"AzureVMAgentCleanUpTask: cleanVMs: node {0} was set offline by user, skipping",
agentNode.getDisplayName());
continue;
}

// If the machine is in "keep" state, skip
if (agentNode.isCleanUpBlocked()) {
LOGGER.log(Level.INFO,
LOGGER.log(getNormalLoggingLevel(),
"AzureVMAgentCleanUpTask: cleanVMs: node {0} blocked to cleanup",
agentNode.getDisplayName());
continue;
Expand All @@ -512,7 +512,7 @@ private void cleanVMs(ExecutionEngine executionEngine) {
// Check if the virtual machine exists. If not, it could have been
// deleted in the background. Remove from Jenkins if that is the case.
if (!AzureVMManagementServiceDelegate.virtualMachineExists(agentNode)) {
LOGGER.log(Level.INFO,
LOGGER.log(getNormalLoggingLevel(),
"AzureVMAgentCleanUpTask: cleanVMs: node {0} doesn't exist, removing",
agentNode.getDisplayName());
try {
Expand All @@ -532,12 +532,12 @@ private void cleanVMs(ExecutionEngine executionEngine) {
public Void call() throws Exception {
// Depending on the cleanup action, run the appropriate
if (agentNode.getCleanUpAction() == CleanUpAction.DELETE) {
LOGGER.log(Level.INFO,
LOGGER.log(getNormalLoggingLevel(),
"AzureVMAgentCleanUpTask: cleanVMs: deleting {0}",
agentNode.getDisplayName());
agentNode.deprovision(agentNode.getCleanUpReason());
} else if (agentNode.getCleanUpAction() == CleanUpAction.SHUTDOWN) {
LOGGER.log(Level.INFO,
LOGGER.log(getNormalLoggingLevel(),
"AzureVMAgentCleanUpTask: cleanVMs: shutting down {0}",
agentNode.getDisplayName());
agentNode.shutdown(agentNode.getCleanUpReason());
Expand All @@ -562,7 +562,7 @@ public Void call() throws Exception {
));
} catch (AzureCloudException exception) {
// No need to throw exception back, just log and move on.
LOGGER.log(Level.INFO,
LOGGER.log(Level.WARNING,
"AzureVMAgentCleanUpTask: cleanVMs: failed to shutdown/delete "
+ agentNode.getDisplayName(),
exception);
Expand Down Expand Up @@ -624,7 +624,7 @@ private void clean() {

@Override
public void execute(TaskListener arg0) throws InterruptedException {
LOGGER.log(Level.INFO, "AzureVMAgentCleanUpTask: execute: start");
LOGGER.log(getNormalLoggingLevel(), "AzureVMAgentCleanUpTask: execute: start");

Callable<Void> callClean = new Callable<Void>() {
@Override
Expand All @@ -637,7 +637,8 @@ public Void call() throws Exception {
Future<Void> result = AzureVMCloud.getThreadPool().submit(callClean);

try {
LOGGER.info("AzureVMAgentCleanUpTask: execute: Running clean with 5 minute timeout");
LOGGER.log(getNormalLoggingLevel(), "AzureVMAgentCleanUpTask: execute: Running clean with 5 minute "
+ "timeout");
// Get will block until time expires or until task completes
result.get(CLEAN_TIMEOUT_IN_MINUTES, TimeUnit.MINUTES);
} catch (ExecutionException executionException) {
Expand All @@ -654,7 +655,7 @@ public Void call() throws Exception {
others);
}

LOGGER.info("AzureVMAgentCleanUpTask: execute: end");
LOGGER.log(getNormalLoggingLevel(), "AzureVMAgentCleanUpTask: execute: end");
}

@Override
Expand Down
29 changes: 17 additions & 12 deletions src/main/java/com/microsoft/azure/vmagent/AzureVMCloudVerificationTask.java
View file
Expand Up @@ -47,14 +47,14 @@ public static void verify(String cloudName, String templateName) {

final AzureVMCloud cloud = getCloud(cloudName);
if (cloud == null) {
LOGGER.log(Level.INFO,
LOGGER.log(getStaticNormalLoggingLevel(),
"AzureVMCloudVerificationTask: verify: parent cloud not found for {0} in {1}",
new Object[]{templateName, cloudName});
return;
}
final AzureVMAgentTemplate agentTemplate = cloud.getAzureAgentTemplate(templateName);
if (agentTemplate == null) {
LOGGER.log(Level.INFO,
LOGGER.log(getStaticNormalLoggingLevel(),
"AzureVMCloudVerificationTask: verify: "
+ "could not retrieve agent template named {0} in {1}",
new Object[]{templateName, cloudName});
Expand All @@ -81,7 +81,7 @@ public static void verify(String cloudName, String templateName) {
try {
List<String> errors = agentTemplate.verifyTemplate();
if (errors.isEmpty()) {
LOGGER.log(Level.FINE,
LOGGER.log(getStaticNormalLoggingLevel(),
"AzureVMCloudVerificationTask: verify: {0} verified successfully",
templateName);
// Verified, set the template to verified.
Expand Down Expand Up @@ -111,15 +111,15 @@ private static void verifyCloud(String cloudName) {
if (StringUtils.isBlank(cloudName)) {
return;
}
LOGGER.log(Level.FINE,
LOGGER.log(getStaticNormalLoggingLevel(),
"AzureVMCloudVerificationTask: verify: verifying cloud {0}",
cloudName);

AzureVMCloud cloud = getCloud(cloudName);

// Unknown cloud. Maybe the name changed
if (cloud == null) {
LOGGER.log(Level.INFO,
LOGGER.log(getStaticNormalLoggingLevel(),
"AzureVMCloudVerificationTask: verify: subscription {0} not found, skipping",
cloudName);
return;
Expand All @@ -128,7 +128,7 @@ private static void verifyCloud(String cloudName) {
synchronized (cloud) {
// Only if verified pass, return at once
if (cloud.getConfigurationStatus().equals(Constants.VERIFIED_PASS)) {
LOGGER.log(Level.FINE,
LOGGER.log(getStaticNormalLoggingLevel(),
"AzureVMCloudVerificationTask: verify: cloud {0} already verified pass",
cloudName);
// Update the count.
Expand All @@ -138,7 +138,8 @@ private static void verifyCloud(String cloudName) {

// Verify. Update the VM count before setting to valid
if (verifyConfiguration(cloud)) {
LOGGER.log(Level.FINE, "AzureVMCloudVerificationTask: validate: {0} verified pass", cloudName);
LOGGER.log(getStaticNormalLoggingLevel(), "AzureVMCloudVerificationTask: validate: {0} "
+ "verified pass", cloudName);
// Update the count
cloud.setVirtualMachineCount(getVirtualMachineCount(cloud));
// We grab the current VM count and
Expand All @@ -163,15 +164,15 @@ private static void verifyCloud(String cloudName) {
* return
*/
public static boolean verifyConfiguration(AzureVMCloud cloud) {
LOGGER.info("AzureVMCloudVerificationTask: verifyConfiguration: start");
LOGGER.log(getStaticNormalLoggingLevel(), "AzureVMCloudVerificationTask: verifyConfiguration: start");

// Check the sub and off we go
String result = cloud.getServiceDelegate().verifyConfiguration(
cloud.getResourceGroupName(),
Integer.toString(cloud.getMaxVirtualMachinesLimit()),
Integer.toString(cloud.getDeploymentTimeout()));
if (!Constants.OP_SUCCESS.equals(result)) {
LOGGER.log(Level.INFO, "AzureVMCloudVerificationTask: verifyConfiguration: {0}", result);
LOGGER.log(getStaticNormalLoggingLevel(), "AzureVMCloudVerificationTask: verifyConfiguration: {0}", result);
cloud.setConfigurationStatus(Constants.VERIFIED_FAILED);
return false;
}
Expand All @@ -186,16 +187,16 @@ public static boolean verifyConfiguration(AzureVMCloud cloud) {
* @return The current VM count
*/
public static int getVirtualMachineCount(AzureVMCloud cloud) {
LOGGER.info("AzureVMCloudVerificationTask: getVirtualMachineCount: start");
LOGGER.log(getStaticNormalLoggingLevel(), "AzureVMCloudVerificationTask: getVirtualMachineCount: start");
try {
int vmCount = cloud.getServiceDelegate().getVirtualMachineCount(cloud.getCloudName(),
cloud.getResourceGroupName());
LOGGER.log(Level.INFO,
LOGGER.log(getStaticNormalLoggingLevel(),
"AzureVMCloudVerificationTask: getVirtualMachineCount: end, cloud {0} has currently {1} vms",
new Object[]{cloud.getCloudName(), vmCount});
return vmCount;
} catch (Exception e) {
LOGGER.log(Level.INFO,
LOGGER.log(getStaticNormalLoggingLevel(),
"AzureVMCloudVerificationTask: getVirtualMachineCount: failed to retrieve vm count:\n{0}",
e.toString());
// We could have failed for any number of reasons. Just return the current
Expand Down Expand Up @@ -230,4 +231,8 @@ public long getRecurrencePeriod() {
protected Level getNormalLoggingLevel() {
return Level.FINE;
}

private static Level getStaticNormalLoggingLevel() {
return Level.FINE;
}
}
6 changes: 3 additions & 3 deletions src/main/java/com/microsoft/azure/vmagent/AzureVMMaintainPoolTask.java
View file
Expand Up @@ -27,12 +27,12 @@ public AzureVMMaintainPoolTask() {
}

public void maintain(AzureVMCloud cloud, AzureVMAgentTemplate template) {
LOGGER.log(Level.INFO, "Starting to maintain template: {0}", template.getTemplateName());
LOGGER.log(getNormalLoggingLevel(), "Starting to maintain template: {0}", template.getTemplateName());
int currentSize = 0;
final int sizeLimit = ((AzureVMCloudPoolRetentionStrategy) template.getRetentionStrategy()).getPoolSize();

if (PoolLock.checkProvisionLock(template)) {
LOGGER.log(Level.INFO, "Agents of template {0} is creating, check later", template);
LOGGER.log(getNormalLoggingLevel(), "Agents of template {0} is creating, check later", template);
return;
}

Expand All @@ -48,7 +48,7 @@ public void maintain(AzureVMCloud cloud, AzureVMAgentTemplate template) {
}
}
if (currentSize < sizeLimit) {
LOGGER.log(Level.INFO, "Prepare for provisioning {0} agents for template {1}",
LOGGER.log(getNormalLoggingLevel(), "Prepare for provisioning {0} agents for template {1}",
new Object[]{sizeLimit - currentSize, template.getTemplateName()});
provisionNodes(cloud, template, sizeLimit - currentSize);
}
Expand Down

0 comments on commit e4e3852

Please sign in to comment.