Skip to content

Commit 87381d4

Browse files
kelvenykelveny
committed
CLOUDSTACK-5725: put origin flow context id into log4j context prefix to link jobs with the orchestration work flow in logging
1 parent ad6454d commit 87381d4

5 files changed

Lines changed: 40 additions & 11 deletions

File tree

‎engine/orchestration/src/com/cloud/vm/VirtualMachineManagerImpl.java‎

Lines changed: 11 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -4161,6 +4161,7 @@ public Object[] doInTransaction(TransactionStatus status) {
41614161
workJob.setStep(VmWorkJobVO.Step.Starting);
41624162
workJob.setVmType(vm.getType());
41634163
workJob.setVmInstanceId(vm.getId());
4164+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
41644165

41654166
// save work context info (there are some duplications)
41664167
VmWorkStart workInfo = new VmWorkStart(callingUser.getId(), callingAccount.getId(), vm.getId(), VirtualMachineManagerImpl.VM_WORK_JOB_HANDLER);
@@ -4213,6 +4214,7 @@ public Object[] doInTransaction(TransactionStatus status) {
42134214
workJob.setStep(VmWorkJobVO.Step.Prepare);
42144215
workJob.setVmType(vm.getType());
42154216
workJob.setVmInstanceId(vm.getId());
4217+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
42164218

42174219
// save work context info (there are some duplications)
42184220
VmWorkStop workInfo = new VmWorkStop(user.getId(), account.getId(), vm.getId(), VirtualMachineManagerImpl.VM_WORK_JOB_HANDLER, cleanup);
@@ -4265,6 +4267,7 @@ public Object[] doInTransaction(TransactionStatus status) {
42654267
workJob.setStep(VmWorkJobVO.Step.Prepare);
42664268
workJob.setVmType(vm.getType());
42674269
workJob.setVmInstanceId(vm.getId());
4270+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
42684271

42694272
// save work context info (there are some duplications)
42704273
VmWorkReboot workInfo = new VmWorkReboot(user.getId(), account.getId(), vm.getId(), VirtualMachineManagerImpl.VM_WORK_JOB_HANDLER, params);
@@ -4314,6 +4317,7 @@ public Object[] doInTransaction(TransactionStatus status) {
43144317
workJob.setUserId(user.getId());
43154318
workJob.setVmType(vm.getType());
43164319
workJob.setVmInstanceId(vm.getId());
4320+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
43174321

43184322
// save work context info (there are some duplications)
43194323
VmWorkMigrate workInfo = new VmWorkMigrate(user.getId(), account.getId(), vm.getId(), VirtualMachineManagerImpl.VM_WORK_JOB_HANDLER, srcHostId, dest);
@@ -4367,6 +4371,7 @@ public Object[] doInTransaction(TransactionStatus status) {
43674371
workJob.setUserId(user.getId());
43684372
workJob.setVmType(vm.getType());
43694373
workJob.setVmInstanceId(vm.getId());
4374+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
43704375

43714376
// save work context info (there are some duplications)
43724377
VmWorkMigrateWithStorage workInfo = new VmWorkMigrateWithStorage(user.getId(), account.getId(), vm.getId(),
@@ -4418,6 +4423,7 @@ public Object[] doInTransaction(TransactionStatus status) {
44184423
workJob.setUserId(user.getId());
44194424
workJob.setVmType(vm.getType());
44204425
workJob.setVmInstanceId(vm.getId());
4426+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
44214427

44224428
// save work context info (there are some duplications)
44234429
VmWorkMigrateForScale workInfo = new VmWorkMigrateForScale(user.getId(), account.getId(), vm.getId(),
@@ -4469,6 +4475,7 @@ public Object[] doInTransaction(TransactionStatus status) {
44694475
workJob.setUserId(user.getId());
44704476
workJob.setVmType(vm.getType());
44714477
workJob.setVmInstanceId(vm.getId());
4478+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
44724479

44734480
// save work context info (there are some duplications)
44744481
VmWorkStorageMigration workInfo = new VmWorkStorageMigration(user.getId(), account.getId(), vm.getId(),
@@ -4518,6 +4525,7 @@ public Object[] doInTransaction(TransactionStatus status) {
45184525
workJob.setUserId(user.getId());
45194526
workJob.setVmType(vm.getType());
45204527
workJob.setVmInstanceId(vm.getId());
4528+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
45214529

45224530
// save work context info (there are some duplications)
45234531
VmWorkAddVmToNetwork workInfo = new VmWorkAddVmToNetwork(user.getId(), account.getId(), vm.getId(),
@@ -4566,6 +4574,7 @@ public Object[] doInTransaction(TransactionStatus status) {
45664574
workJob.setUserId(user.getId());
45674575
workJob.setVmType(vm.getType());
45684576
workJob.setVmInstanceId(vm.getId());
4577+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
45694578

45704579
// save work context info (there are some duplications)
45714580
VmWorkRemoveNicFromVm workInfo = new VmWorkRemoveNicFromVm(user.getId(), account.getId(), vm.getId(),
@@ -4614,6 +4623,7 @@ public Object[] doInTransaction(TransactionStatus status) {
46144623
workJob.setUserId(user.getId());
46154624
workJob.setVmType(vm.getType());
46164625
workJob.setVmInstanceId(vm.getId());
4626+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
46174627

46184628
// save work context info (there are some duplications)
46194629
VmWorkRemoveVmFromNetwork workInfo = new VmWorkRemoveVmFromNetwork(user.getId(), account.getId(), vm.getId(),
@@ -4664,6 +4674,7 @@ public Object[] doInTransaction(TransactionStatus status) {
46644674
workJob.setUserId(user.getId());
46654675
workJob.setVmType(vm.getType());
46664676
workJob.setVmInstanceId(vm.getId());
4677+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
46674678

46684679
// save work context info (there are some duplications)
46694680
VmWorkReconfigure workInfo = new VmWorkReconfigure(user.getId(), account.getId(), vm.getId(),

‎engine/orchestration/src/com/cloud/vm/VmWorkJobDispatcher.java‎

Lines changed: 9 additions & 7 deletions
Original file line numberDiff line numberDiff line change
@@ -62,35 +62,37 @@ public void runJob(AsyncJob job) {
6262
assert (cmd != null);
6363

6464
if (s_logger.isDebugEnabled())
65-
s_logger.debug("Run VM work job: " + cmd);
65+
s_logger.debug("Run VM work job: " + cmd + ", job origin: " + job.getRelated());
6666

6767
Class<?> workClz = null;
6868
try {
6969
workClz = Class.forName(job.getCmd());
7070
} catch (ClassNotFoundException e) {
71-
s_logger.error("VM work class " + cmd + " is not found", e);
71+
s_logger.error("VM work class " + cmd + " is not found" + ", job origin: " + job.getRelated(), e);
7272
_asyncJobMgr.completeAsyncJob(job.getId(), JobInfo.Status.FAILED, 0, e.getMessage());
7373
return;
7474
}
7575

7676
work = VmWorkSerializer.deserialize(workClz, job.getCmdInfo());
7777
assert(work != null);
7878
if(work == null) {
79-
s_logger.error("Unable to deserialize VM work " + job.getCmd() + ", job info: " + job.getCmdInfo());
79+
s_logger.error("Unable to deserialize VM work " + job.getCmd() + ", job info: " + job.getCmdInfo() + ", job origin: " + job.getRelated());
8080
_asyncJobMgr.completeAsyncJob(job.getId(), JobInfo.Status.FAILED, 0, "Unable to deserialize VM work");
8181
return;
8282
}
8383

8484
if (_handlers == null || _handlers.isEmpty()) {
85-
s_logger.error("Invalid startup configuration, no work job handler is found. cmd: " + job.getCmd() + ", job info: " + job.getCmdInfo());
85+
s_logger.error("Invalid startup configuration, no work job handler is found. cmd: " + job.getCmd() + ", job info: " + job.getCmdInfo()
86+
+ ", job origin: " + job.getRelated());
8687
_asyncJobMgr.completeAsyncJob(job.getId(), JobInfo.Status.FAILED, 0, "Invalid startup configuration. no job handler is found");
8788
return;
8889
}
8990

9091
VmWorkJobHandler handler = _handlers.get(work.getHandlerName());
9192

9293
if (handler == null) {
93-
s_logger.error("Unable to find work job handler. handler name: " + work.getHandlerName() + ", job cmd: " + job.getCmd() + ", job info: " + job.getCmdInfo());
94+
s_logger.error("Unable to find work job handler. handler name: " + work.getHandlerName() + ", job cmd: " + job.getCmd()
95+
+ ", job info: " + job.getCmdInfo() + ", job origin: " + job.getRelated());
9496
_asyncJobMgr.completeAsyncJob(job.getId(), JobInfo.Status.FAILED, 0, "Unable to find work job handler");
9597
return;
9698
}
@@ -101,10 +103,10 @@ public void runJob(AsyncJob job) {
101103
_asyncJobMgr.completeAsyncJob(job.getId(), result.first(), 0, result.second());
102104

103105
} catch(Throwable e) {
104-
s_logger.error("Unable to complete " + job, e);
106+
s_logger.error("Unable to complete " + job + ", job origin:" + job.getRelated(), e);
105107

106108
String exceptionJson = JobSerializerHelper.toSerializedString(e);
107-
s_logger.info("Serialize exception object into json: " + exceptionJson);
109+
s_logger.info("Serialize exception object into json: " + exceptionJson + ", job origin: " + job.getRelated());
108110
_asyncJobMgr.completeAsyncJob(job.getId(), JobInfo.Status.FAILED, 0, exceptionJson);
109111
} finally {
110112
CallContext.unregister();

‎framework/jobs/src/org/apache/cloudstack/framework/jobs/AsyncJobExecutionContext.java‎

Lines changed: 11 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -18,6 +18,7 @@
1818

1919
import org.apache.log4j.Logger;
2020

21+
import org.apache.cloudstack.context.CallContext;
2122
import org.apache.cloudstack.framework.jobs.dao.AsyncJobJoinMapDao;
2223
import org.apache.cloudstack.framework.jobs.impl.AsyncJobJoinMapVO;
2324
import org.apache.cloudstack.framework.jobs.impl.JobSerializerHelper;
@@ -103,17 +104,19 @@ public void joinJob(long joinJobId) {
103104
s_jobMgr.joinJob(_job.getId(), joinJobId);
104105
}
105106

106-
public void joinJob(long joinJobId, String wakeupHandler, String wakeupDispatcher, String[] wakeupTopcisOnMessageBus, long wakeupIntervalInMilliSeconds,
107-
long timeoutInMilliSeconds) {
107+
public void joinJob(long joinJobId, String wakeupHandler, String wakeupDispatcher,
108+
String[] wakeupTopcisOnMessageBus, long wakeupIntervalInMilliSeconds, long timeoutInMilliSeconds) {
108109
assert (_job != null);
109-
s_jobMgr.joinJob(_job.getId(), joinJobId, wakeupHandler, wakeupDispatcher, wakeupTopcisOnMessageBus, wakeupIntervalInMilliSeconds, timeoutInMilliSeconds);
110+
s_jobMgr.joinJob(_job.getId(), joinJobId, wakeupHandler, wakeupDispatcher, wakeupTopcisOnMessageBus,
111+
wakeupIntervalInMilliSeconds, timeoutInMilliSeconds);
110112
}
111113

112114
//
113115
// check failure exception before we disjoin the worker job
114116
// TODO : it is ugly and this will become unnecessary after we switch to full-async mode
115117
//
116-
public void disjoinJob(long joinedJobId) throws InsufficientCapacityException, ConcurrentOperationException, ResourceUnavailableException {
118+
public void disjoinJob(long joinedJobId) throws InsufficientCapacityException,
119+
ConcurrentOperationException, ResourceUnavailableException {
117120
assert (_job != null);
118121

119122
AsyncJobJoinMapVO record = s_joinMapDao.getJoinRecord(_job.getId(), joinedJobId);
@@ -171,4 +174,8 @@ public static AsyncJobExecutionContext unregister() {
171174
public static void setCurrentExecutionContext(AsyncJobExecutionContext currentContext) {
172175
s_currentExectionContext.set(currentContext);
173176
}
177+
178+
public static String getOriginJobContextId() {
179+
return String.valueOf(CallContext.current().getContextId());
180+
}
174181
}

‎server/src/com/cloud/storage/VolumeApiServiceImpl.java‎

Lines changed: 5 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -2147,6 +2147,7 @@ public Object[] doInTransaction(TransactionStatus status) {
21472147
workJob.setStep(VmWorkJobVO.Step.Starting);
21482148
workJob.setVmType(vm.getType());
21492149
workJob.setVmInstanceId(vm.getId());
2150+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
21502151

21512152
// save work context info (there are some duplications)
21522153
VmWorkAttachVolume workInfo = new VmWorkAttachVolume(callingUser.getId(), callingAccount.getId(), vm.getId(), VolumeApiServiceImpl.VM_WORK_JOB_HANDLER, volumeId,
@@ -2193,6 +2194,7 @@ public Object[] doInTransaction(TransactionStatus status) {
21932194
workJob.setStep(VmWorkJobVO.Step.Starting);
21942195
workJob.setVmType(vm.getType());
21952196
workJob.setVmInstanceId(vm.getId());
2197+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
21962198

21972199
// save work context info (there are some duplications)
21982200
VmWorkDetachVolume workInfo = new VmWorkDetachVolume(callingUser.getId(), callingAccount.getId(), vm.getId(), VolumeApiServiceImpl.VM_WORK_JOB_HANDLER, volumeId);
@@ -2236,6 +2238,7 @@ public Object[] doInTransaction(TransactionStatus status) {
22362238
workJob.setStep(VmWorkJobVO.Step.Starting);
22372239
workJob.setVmType(vm.getType());
22382240
workJob.setVmInstanceId(vm.getId());
2241+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
22392242

22402243
// save work context info (there are some duplications)
22412244
VmWorkResizeVolume workInfo = new VmWorkResizeVolume(callingUser.getId(), callingAccount.getId(), vm.getId(),
@@ -2280,6 +2283,7 @@ public Object[] doInTransaction(TransactionStatus status) {
22802283
workJob.setStep(VmWorkJobVO.Step.Starting);
22812284
workJob.setVmType(vm.getType());
22822285
workJob.setVmInstanceId(vm.getId());
2286+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
22832287

22842288
// save work context info (there are some duplications)
22852289
VmWorkMigrateVolume workInfo = new VmWorkMigrateVolume(callingUser.getId(), callingAccount.getId(), vm.getId(),
@@ -2324,6 +2328,7 @@ public Object[] doInTransaction(TransactionStatus status) {
23242328
workJob.setStep(VmWorkJobVO.Step.Starting);
23252329
workJob.setVmType(vm.getType());
23262330
workJob.setVmInstanceId(vm.getId());
2331+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
23272332

23282333
// save work context info (there are some duplications)
23292334
VmWorkTakeVolumeSnapshot workInfo = new VmWorkTakeVolumeSnapshot(

‎server/src/com/cloud/vm/snapshot/VMSnapshotManagerImpl.java‎

Lines changed: 4 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -830,6 +830,7 @@ public Object[] doInTransaction(TransactionStatus status) {
830830
workJob.setStep(VmWorkJobVO.Step.Starting);
831831
workJob.setVmType(vm.getType());
832832
workJob.setVmInstanceId(vm.getId());
833+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
833834

834835
// save work context info (there are some duplications)
835836
VmWorkCreateVMSnapshot workInfo = new VmWorkCreateVMSnapshot(callingUser.getId(), callingAccount.getId(), vm.getId(),
@@ -873,6 +874,7 @@ public Object[] doInTransaction(TransactionStatus status) {
873874
workJob.setStep(VmWorkJobVO.Step.Starting);
874875
workJob.setVmType(vm.getType());
875876
workJob.setVmInstanceId(vm.getId());
877+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
876878

877879
// save work context info (there are some duplications)
878880
VmWorkDeleteVMSnapshot workInfo = new VmWorkDeleteVMSnapshot(callingUser.getId(), callingAccount.getId(), vm.getId(),
@@ -916,6 +918,7 @@ public Object[] doInTransaction(TransactionStatus status) {
916918
workJob.setStep(VmWorkJobVO.Step.Starting);
917919
workJob.setVmType(vm.getType());
918920
workJob.setVmInstanceId(vm.getId());
921+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
919922

920923
// save work context info (there are some duplications)
921924
VmWorkRevertToVMSnapshot workInfo = new VmWorkRevertToVMSnapshot(callingUser.getId(), callingAccount.getId(), vm.getId(),
@@ -959,6 +962,7 @@ public Object[] doInTransaction(TransactionStatus status) {
959962
workJob.setStep(VmWorkJobVO.Step.Starting);
960963
workJob.setVmType(vm.getType());
961964
workJob.setVmInstanceId(vm.getId());
965+
workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
962966

963967
// save work context info (there are some duplications)
964968
VmWorkDeleteAllVMSnapshots workInfo = new VmWorkDeleteAllVMSnapshots(callingUser.getId(), callingAccount.getId(), vm.getId(),

0 commit comments

Comments
 (0)