Skip to content

Commit 67983fe

Browse files
pjdartonpjdarton
committed
Improved logging:
VSphere no longer logs to stdout. Improved exception logging - now includes stacktraces. Added extra detail into some textual output for easier diagnosis.
1 parent ff8e75a commit 67983fe

3 files changed

Lines changed: 79 additions & 65 deletions

File tree

‎src/main/java/org/jenkinsci/plugins/vSphereCloudLauncher.java‎

Lines changed: 21 additions & 14 deletions
Original file line numberDiff line numberDiff line change
@@ -144,14 +144,14 @@ public void launch(SlaveComputer slaveComputer, TaskListener taskListener)
144144
v = vsC.vSphereInstance();
145145
VirtualMachine vm = v.getVmByName(vmName);
146146
if (vm == null) {
147-
throw new IOException("Virtual Machine could not be found");
147+
throw new IOException("Virtual Machine '" + vmName + "' could not be found");
148148
}
149149

150150
// Revert to a snapshot - always - if one is specified.
151151
if (!snapName.isEmpty()) {
152152
VirtualMachineSnapshot snap = v.getSnapshotInTree(vm, snapName);
153153
if (snap == null) {
154-
throw new IOException("Virtual Machine snapshot cannot be found");
154+
throw new IOException("Virtual Machine '" + vmName + "' snapshot '" + snapName + "' cannot be found");
155155
}
156156

157157
vSphereCloud.Log(slaveComputer, taskListener, "Reverting to snapshot:" + snapName);
@@ -194,13 +194,21 @@ public void launch(SlaveComputer slaveComputer, TaskListener taskListener)
194194
* Now we wait our launch delay amount before trying to connect.
195195
*/
196196
if (delegate.isLaunchSupported()) {
197-
// Delegate is going to do launch.
198-
Thread.sleep(launchDelay * 1000);
197+
if (launchDelay > 0) {
198+
vSphereCloud.Log(slaveComputer, taskListener, "Waiting for " + launchDelay
199+
+ " seconds before asking " + delegate + " to launch slave.");
200+
// Delegate is going to do launch.
201+
Thread.sleep(launchDelay * 1000);
202+
}
203+
vSphereCloud.Log(slaveComputer, taskListener, "Asking " + delegate.getClass().getSimpleName() + " to launch slave.");
199204
delegate.launch(slaveComputer, taskListener);
200205
} else {
206+
vSphereCloud.Log(slaveComputer, taskListener, "Waiting for up to " + launchDelay
207+
+ " seconds for slave to come online.");
201208
for (int i = 0; i <= launchDelay; i++) {
202209
Thread.sleep(1000);
203210
if (slaveComputer.isOnline()) {
211+
vSphereCloud.Log(slaveComputer, taskListener, "Slave has come online.");
204212
break;
205213
}
206214
}
@@ -209,9 +217,9 @@ public void launch(SlaveComputer slaveComputer, TaskListener taskListener)
209217
throw new IOException("Slave did not come online in allowed time");
210218
}
211219
}
220+
vSphereCloud.Log(slaveComputer, taskListener, "Slave online");
212221
} catch (final Exception e) {
213-
vSphereCloud.Log(slaveComputer, taskListener, "EXCEPTION while starting VM");
214-
vSphereCloud.Log(slaveComputer, taskListener, e.getMessage());
222+
vSphereCloud.Log(slaveComputer, taskListener, e, "EXCEPTION while starting VM");
215223
vsC.markVMOffline(slaveComputer.getDisplayName(), vmName);
216224
throw new RuntimeException(e);
217225
} finally {
@@ -220,6 +228,8 @@ public void launch(SlaveComputer slaveComputer, TaskListener taskListener)
220228
if (v != null)
221229
v.disconnect();
222230
}
231+
} catch (final RuntimeException e) {
232+
throw e;
223233
} catch (final Exception e) {
224234
throw new RuntimeException(e);
225235
}
@@ -301,12 +311,11 @@ public synchronized void afterDisconnect(SlaveComputer slaveComputer, TaskListen
301311
// VM is already powered down.
302312
}
303313
}
304-
if (v != null)
314+
if (v != null) {
305315
v.disconnect();
316+
}
306317
} catch (Throwable t) {
307-
vSphereCloud.Log(slaveComputer, taskListener, "Got an exception");
308-
vSphereCloud.Log(slaveComputer, taskListener, t.toString());
309-
vSphereCloud.Log(slaveComputer, taskListener, "Printed exception");
318+
vSphereCloud.Log(slaveComputer, taskListener, t, "Got an exception");
310319
taskListener.fatalError(t.getMessage(), t);
311320
} finally {
312321
vsSlave.slaveIsDisconnecting = Boolean.FALSE;
@@ -391,10 +400,8 @@ private void shutdownVM(VirtualMachine vm, SlaveComputer slaveComputer, TaskList
391400
Thread.sleep(5000);
392401
}
393402
} catch (Throwable t) {
394-
vSphereCloud.Log(slaveComputer, taskListener,
403+
vSphereCloud.Log(slaveComputer, taskListener, t,
395404
"Got an exception while attempting a graceful shutdown");
396-
vSphereCloud.Log(slaveComputer, taskListener, t.toString());
397-
vSphereCloud.Log(slaveComputer, taskListener, "Printed exception");
398405
vSphereCloud.Log(slaveComputer, taskListener, "Will now attempt a hard power down");
399406
}
400407
}
@@ -444,7 +451,7 @@ private void suspendVM(VirtualMachine vm, SlaveComputer slaveComputer, TaskListe
444451
vSphereCloud.Log(slaveComputer, taskListener, "Suspending the VM");
445452
Task task = vm.suspendVM_Task();
446453
if (!task.waitForTask().equals(Task.SUCCESS)) {
447-
vSphereCloud.Log(slaveComputer, taskListener, "Unable to susped the VM");
454+
vSphereCloud.Log(slaveComputer, taskListener, "Unable to suspend the VM");
448455
}
449456
}
450457
}

‎src/main/java/org/jenkinsci/plugins/vSphereCloudSlave.java‎

Lines changed: 23 additions & 24 deletions
Original file line numberDiff line numberDiff line change
@@ -1,9 +1,5 @@
1-
/*
2-
* To change this template, choose Tools | Templates
3-
* and open the template in the editor.
4-
*/
51
package org.jenkinsci.plugins;
6-
2+
73
import hudson.AbortException;
84
import hudson.Extension;
95
import hudson.Functions;
@@ -26,14 +22,17 @@
2622

2723
import com.vmware.vim25.mo.VirtualMachine;
2824
import com.vmware.vim25.mo.VirtualMachineSnapshot;
25+
2926
import hudson.model.Executor;
3027
import hudson.model.Queue;
28+
3129
import java.util.ArrayList;
3230
import java.util.Date;
3331
import java.util.Iterator;
3432
import java.util.List;
3533
import java.util.Map.Entry;
3634
import java.util.concurrent.ConcurrentHashMap;
35+
3736
import jenkins.model.Jenkins;
3837

3938
/**
@@ -48,7 +47,9 @@ public class vSphereCloudSlave extends AbstractCloudSlave {
4847
private final Boolean waitForVMTools;
4948
private final String launchDelay;
5049
private final String idleOption;
51-
private Integer LimitedTestRunCount = 0; // If limited test runs enabled, the number of tests to limit the slave too.
50+
/** If more than zero then this is the number of build-jobs we limit the slave to. */
51+
private Integer LimitedTestRunCount = 0;
52+
/** A count of the number of build-jobs this slave has done. */
5253
private transient Integer NumberOfLimitedTestRuns = 0;
5354
public transient Boolean doingLastInLimitedTestRun = Boolean.FALSE;
5455

@@ -85,7 +86,7 @@ public vSphereCloudSlave(String name, String nodeDescription,
8586
this.NumberOfLimitedTestRuns = 0;
8687
readResolve();
8788
}
88-
89+
8990
@Override
9091
protected Object readResolve() {
9192
super.readResolve();
@@ -97,7 +98,7 @@ protected Object readResolve() {
9798
}
9899
return this;
99100
}
100-
101+
101102
public String getVmName() {
102103
return vmName;
103104
}
@@ -141,10 +142,10 @@ public String toString() {
141142
return "Shutting down VSphere Cloud Slave";
142143
}
143144
});
144-
vSphereCloud.Log("Disconnected computer");
145+
vSphereCloud.Log(this, listener, "Disconnected computer");
145146
}
146147
} catch(Exception e) {
147-
vSphereCloud.Log("Can't disconnect: \n" + e.getMessage());
148+
vSphereCloud.Log(this, listener, e, "Can't disconnect");
148149
}
149150
}
150151

@@ -224,7 +225,7 @@ public static vSphereCloudSlave ProbablyLaunchCanHandle(BuildableItem item) {
224225
public AbstractCloudComputer createComputer() {
225226
return new vSphereCloudSlaveComputer(this);
226227
}
227-
228+
228229
@Override
229230
public CauseOfBlockage canTake(BuildableItem buildItem) {
230231
// https://issues.jenkins-ci.org/browse/JENKINS-30203
@@ -236,15 +237,15 @@ public String getShortDescription() {
236237
}
237238
};
238239
}
239-
240+
240241
if(slaveIsStarting == Boolean.TRUE) {
241242
return new CauseOfBlockage.BecauseNodeIsBusy(this);
242243
}
243-
244+
244245
if (slaveIsDisconnecting == Boolean.TRUE) {
245246
return new CauseOfBlockage.BecauseNodeIsOffline(this);
246247
}
247-
248+
248249
return super.canTake(buildItem);
249250
}
250251

@@ -267,11 +268,11 @@ public boolean StartLimitedTestRun(Run r, TaskListener listener) {
267268
if (executor != null && DoUpdates) {
268269
if (ret) {
269270
NumberOfLimitedTestRuns++;
270-
vSphereCloud.Log(listener, "Starting limited count build: %d", NumberOfLimitedTestRuns);
271+
vSphereCloud.Log(this, listener, "Starting limited count build: %d of %d", NumberOfLimitedTestRuns, LimitedTestRunCount);
271272
Computer slave = executor.getOwner();
272273
RunToSlaveMapper.put(r, slave);
273274
} else {
274-
vSphereCloud.Log(listener, "Terminating build due to limited build count: %d", LimitedTestRunCount);
275+
vSphereCloud.Log(this, listener, "Terminating build due to limited build count: %d of %d", NumberOfLimitedTestRuns, LimitedTestRunCount);
275276
executor.interrupt(Result.ABORTED);
276277
}
277278
}
@@ -281,7 +282,7 @@ public boolean StartLimitedTestRun(Run r, TaskListener listener) {
281282

282283
public boolean EndLimitedTestRun(Run r) {
283284
boolean ret = true;
284-
285+
285286
// See if the run maps to an existing computer; remove if found.
286287
Computer slave = RunToSlaveMapper.get(r);
287288
if (slave != null) {
@@ -294,20 +295,20 @@ public boolean EndLimitedTestRun(Run r) {
294295
NumberOfLimitedTestRuns = 0;
295296
try {
296297
if (slave != null) {
297-
vSphereCloud.Log("Disconnecting the slave agent on %s due to limited build threshold", slave.getName());
298-
298+
vSphereCloud.Log(this, "Disconnecting the slave agent on %s due to limited build threshold", slave.getName());
299+
299300
slave.setTemporarilyOffline(true, new OfflineCause.ByCLI("vSphere Plugin marking the slave as offline due to reaching limited build threshold"));
300301
slave.waitUntilOffline();
301302
slave.disconnect(new OfflineCause.ByCLI("vSphere Plugin disconnecting the slave as offline due to reaching limited build threshold"));
302303
slave.setTemporarilyOffline(false, new OfflineCause.ByCLI("vSphere Plugin marking the slave as online after completing post-disconnect actions."));
303304
}
304305
else {
305-
vSphereCloud.Log("Attempting to shutdown slave due to limited build threshold, but cannot determine slave");
306+
vSphereCloud.Log(this, "Attempting to shutdown slave due to limited build threshold, but cannot determine slave");
306307
}
307308
} catch (NullPointerException ex) {
308-
vSphereCloud.Log("NullPointerException thrown while retrieving the slave agent: %s", ex.getMessage());
309+
vSphereCloud.Log(this, ex, "NullPointerException thrown while retrieving the slave agent");
309310
} catch (InterruptedException ex) {
310-
vSphereCloud.Log("InterruptedException thrown while marking the slave as online or offline: %s", ex.getMessage());
311+
vSphereCloud.Log(this, ex, "InterruptedException thrown while marking the slave as online or offline");
311312
}
312313
}
313314
} else {
@@ -316,8 +317,6 @@ public boolean EndLimitedTestRun(Run r) {
316317
return ret;
317318
}
318319

319-
320-
321320
/**
322321
* For UI.
323322
*

0 commit comments

Comments
 (0)