CLOUDSTACK-5725: put origin flow context id into log4j context prefix to link jobs with the orchestration work flow in logging

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

@@ -4161,6 +4161,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac
                     workJob.setStep(VmWorkJobVO.Step.Starting);
                     workJob.setVmType(vm.getType());
                     workJob.setVmInstanceId(vm.getId());
+                    workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                     // save work context info (there are some duplications)
                     VmWorkStart workInfo = new VmWorkStart(callingUser.getId(), callingAccount.getId(), vm.getId(), VirtualMachineManagerImpl.VM_WORK_JOB_HANDLER);
@@ -4213,6 +4214,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac
                     workJob.setStep(VmWorkJobVO.Step.Prepare);
                     workJob.setVmType(vm.getType());
                     workJob.setVmInstanceId(vm.getId());
+                    workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                     // save work context info (there are some duplications)
                     VmWorkStop workInfo = new VmWorkStop(user.getId(), account.getId(), vm.getId(), VirtualMachineManagerImpl.VM_WORK_JOB_HANDLER, cleanup);
@@ -4265,6 +4267,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac
                     workJob.setStep(VmWorkJobVO.Step.Prepare);
                     workJob.setVmType(vm.getType());
                     workJob.setVmInstanceId(vm.getId());
+                    workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                     // save work context info (there are some duplications)
                     VmWorkReboot workInfo = new VmWorkReboot(user.getId(), account.getId(), vm.getId(), VirtualMachineManagerImpl.VM_WORK_JOB_HANDLER, params);
@@ -4314,6 +4317,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac
                     workJob.setUserId(user.getId());
                     workJob.setVmType(vm.getType());
                     workJob.setVmInstanceId(vm.getId());
+                    workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                     // save work context info (there are some duplications)
                     VmWorkMigrate workInfo = new VmWorkMigrate(user.getId(), account.getId(), vm.getId(), VirtualMachineManagerImpl.VM_WORK_JOB_HANDLER, srcHostId, dest);
@@ -4367,6 +4371,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac
                     workJob.setUserId(user.getId());
                     workJob.setVmType(vm.getType());
                     workJob.setVmInstanceId(vm.getId());
+                    workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                     // save work context info (there are some duplications)
                     VmWorkMigrateWithStorage workInfo = new VmWorkMigrateWithStorage(user.getId(), account.getId(), vm.getId(),
@@ -4418,6 +4423,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac
                     workJob.setUserId(user.getId());
                     workJob.setVmType(vm.getType());
                     workJob.setVmInstanceId(vm.getId());
+                    workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                     // save work context info (there are some duplications)
                     VmWorkMigrateForScale workInfo = new VmWorkMigrateForScale(user.getId(), account.getId(), vm.getId(),
@@ -4469,6 +4475,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac
                     workJob.setUserId(user.getId());
                     workJob.setVmType(vm.getType());
                     workJob.setVmInstanceId(vm.getId());
+                    workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                     // save work context info (there are some duplications)
                     VmWorkStorageMigration workInfo = new VmWorkStorageMigration(user.getId(), account.getId(), vm.getId(),
@@ -4518,6 +4525,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac
                     workJob.setUserId(user.getId());
                     workJob.setVmType(vm.getType());
                     workJob.setVmInstanceId(vm.getId());
+                    workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                     // save work context info (there are some duplications)
                     VmWorkAddVmToNetwork workInfo = new VmWorkAddVmToNetwork(user.getId(), account.getId(), vm.getId(),
@@ -4566,6 +4574,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac
                     workJob.setUserId(user.getId());
                     workJob.setVmType(vm.getType());
                     workJob.setVmInstanceId(vm.getId());
+                    workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                     // save work context info (there are some duplications)
                     VmWorkRemoveNicFromVm workInfo = new VmWorkRemoveNicFromVm(user.getId(), account.getId(), vm.getId(),
@@ -4614,6 +4623,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac
                     workJob.setUserId(user.getId());
                     workJob.setVmType(vm.getType());
                     workJob.setVmInstanceId(vm.getId());
+                    workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                     // save work context info (there are some duplications)
                     VmWorkRemoveVmFromNetwork workInfo = new VmWorkRemoveVmFromNetwork(user.getId(), account.getId(), vm.getId(),
@@ -4664,6 +4674,7 @@ public class VirtualMachineManagerImpl extends ManagerBase implements VirtualMac
                     workJob.setUserId(user.getId());
                     workJob.setVmType(vm.getType());
                     workJob.setVmInstanceId(vm.getId());
+                    workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                     // save work context info (there are some duplications)
                     VmWorkReconfigure workInfo = new VmWorkReconfigure(user.getId(), account.getId(), vm.getId(),

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

@@ -62,13 +62,13 @@ public class VmWorkJobDispatcher extends AdapterBase implements AsyncJobDispatch
             assert (cmd != null);
 
             if (s_logger.isDebugEnabled())
-                s_logger.debug("Run VM work job: " + cmd);
+                s_logger.debug("Run VM work job: " + cmd + ", job origin: " + job.getRelated());
 
             Class<?> workClz = null;
             try {
                 workClz = Class.forName(job.getCmd());
             } catch (ClassNotFoundException e) {
-                s_logger.error("VM work class " + cmd + " is not found", e);
+                s_logger.error("VM work class " + cmd + " is not found" + ", job origin: " + job.getRelated(), e);
                 _asyncJobMgr.completeAsyncJob(job.getId(), JobInfo.Status.FAILED, 0, e.getMessage());
                 return;
             }
@@ -76,13 +76,14 @@ public class VmWorkJobDispatcher extends AdapterBase implements AsyncJobDispatch
             work = VmWorkSerializer.deserialize(workClz, job.getCmdInfo());
             assert(work != null);
             if(work == null) {
-                s_logger.error("Unable to deserialize VM work " + job.getCmd() + ", job info: " + job.getCmdInfo());
+                s_logger.error("Unable to deserialize VM work " + job.getCmd() + ", job info: " + job.getCmdInfo() + ", job origin: " + job.getRelated());
                 _asyncJobMgr.completeAsyncJob(job.getId(), JobInfo.Status.FAILED, 0, "Unable to deserialize VM work");
                 return;
             }
 
             if (_handlers == null || _handlers.isEmpty()) {
-                s_logger.error("Invalid startup configuration, no work job handler is found. cmd: " + job.getCmd() + ", job info: " + job.getCmdInfo());
+                s_logger.error("Invalid startup configuration, no work job handler is found. cmd: " + job.getCmd() + ", job info: " + job.getCmdInfo()
+                        + ", job origin: " + job.getRelated());
                 _asyncJobMgr.completeAsyncJob(job.getId(), JobInfo.Status.FAILED, 0, "Invalid startup configuration. no job handler is found");
                 return;
             }
@@ -90,7 +91,8 @@ public class VmWorkJobDispatcher extends AdapterBase implements AsyncJobDispatch
             VmWorkJobHandler handler = _handlers.get(work.getHandlerName());
 
             if (handler == null) {
-                s_logger.error("Unable to find work job handler. handler name: " + work.getHandlerName() + ", job cmd: " + job.getCmd() + ", job info: " + job.getCmdInfo());
+                s_logger.error("Unable to find work job handler. handler name: " + work.getHandlerName() + ", job cmd: " + job.getCmd()
+                        + ", job info: " + job.getCmdInfo() + ", job origin: " + job.getRelated());
                 _asyncJobMgr.completeAsyncJob(job.getId(), JobInfo.Status.FAILED, 0, "Unable to find work job handler");
                 return;
             }
@@ -101,10 +103,10 @@ public class VmWorkJobDispatcher extends AdapterBase implements AsyncJobDispatch
             _asyncJobMgr.completeAsyncJob(job.getId(), result.first(), 0, result.second());
 
         } catch(Throwable e) {
-            s_logger.error("Unable to complete " + job, e);
+            s_logger.error("Unable to complete " + job + ", job origin:" + job.getRelated(), e);
 
             String exceptionJson = JobSerializerHelper.toSerializedString(e);
-            s_logger.info("Serialize exception object into json: " + exceptionJson);
+            s_logger.info("Serialize exception object into json: " + exceptionJson + ", job origin: " + job.getRelated());
             _asyncJobMgr.completeAsyncJob(job.getId(), JobInfo.Status.FAILED, 0, exceptionJson);
         } finally {
             CallContext.unregister();

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

@@ -18,6 +18,7 @@ package org.apache.cloudstack.framework.jobs;
 
 import org.apache.log4j.Logger;
 
+import org.apache.cloudstack.context.CallContext;
 import org.apache.cloudstack.framework.jobs.dao.AsyncJobJoinMapDao;
 import org.apache.cloudstack.framework.jobs.impl.AsyncJobJoinMapVO;
 import org.apache.cloudstack.framework.jobs.impl.JobSerializerHelper;
@@ -103,17 +104,19 @@ public class AsyncJobExecutionContext {
         s_jobMgr.joinJob(_job.getId(), joinJobId);
     }
 
-    public void joinJob(long joinJobId, String wakeupHandler, String wakeupDispatcher, String[] wakeupTopcisOnMessageBus, long wakeupIntervalInMilliSeconds,
+    public void joinJob(long joinJobId, String wakeupHandler, String wakeupDispatcher,
-        long timeoutInMilliSeconds) {
+            String[] wakeupTopcisOnMessageBus, long wakeupIntervalInMilliSeconds, long timeoutInMilliSeconds) {
         assert (_job != null);
-        s_jobMgr.joinJob(_job.getId(), joinJobId, wakeupHandler, wakeupDispatcher, wakeupTopcisOnMessageBus, wakeupIntervalInMilliSeconds, timeoutInMilliSeconds);
+        s_jobMgr.joinJob(_job.getId(), joinJobId, wakeupHandler, wakeupDispatcher, wakeupTopcisOnMessageBus,
+                wakeupIntervalInMilliSeconds, timeoutInMilliSeconds);
     }
 
     //
     // check failure exception before we disjoin the worker job
     // TODO : it is ugly and this will become unnecessary after we switch to full-async mode
     //
-    public void disjoinJob(long joinedJobId) throws InsufficientCapacityException, ConcurrentOperationException, ResourceUnavailableException {
+    public void disjoinJob(long joinedJobId) throws InsufficientCapacityException,
+            ConcurrentOperationException, ResourceUnavailableException {
         assert (_job != null);
 
         AsyncJobJoinMapVO record = s_joinMapDao.getJoinRecord(_job.getId(), joinedJobId);
@@ -171,4 +174,8 @@ public class AsyncJobExecutionContext {
     public static void setCurrentExecutionContext(AsyncJobExecutionContext currentContext) {
         s_currentExectionContext.set(currentContext);
     }
+
+    public static String getOriginJobContextId() {
+        return String.valueOf(CallContext.current().getContextId());
+    }
 }

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

@@ -2147,6 +2147,7 @@ public class VolumeApiServiceImpl extends ManagerBase implements VolumeApiServic
                 workJob.setStep(VmWorkJobVO.Step.Starting);
                 workJob.setVmType(vm.getType());
                 workJob.setVmInstanceId(vm.getId());
+                workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                 // save work context info (there are some duplications)
                 VmWorkAttachVolume workInfo = new VmWorkAttachVolume(callingUser.getId(), callingAccount.getId(), vm.getId(), VolumeApiServiceImpl.VM_WORK_JOB_HANDLER, volumeId,
@@ -2193,6 +2194,7 @@ public class VolumeApiServiceImpl extends ManagerBase implements VolumeApiServic
                 workJob.setStep(VmWorkJobVO.Step.Starting);
                 workJob.setVmType(vm.getType());
                 workJob.setVmInstanceId(vm.getId());
+                workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                 // save work context info (there are some duplications)
                 VmWorkDetachVolume workInfo = new VmWorkDetachVolume(callingUser.getId(), callingAccount.getId(), vm.getId(), VolumeApiServiceImpl.VM_WORK_JOB_HANDLER, volumeId);
@@ -2236,6 +2238,7 @@ public class VolumeApiServiceImpl extends ManagerBase implements VolumeApiServic
                 workJob.setStep(VmWorkJobVO.Step.Starting);
                 workJob.setVmType(vm.getType());
                 workJob.setVmInstanceId(vm.getId());
+                workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                 // save work context info (there are some duplications)
                 VmWorkResizeVolume workInfo = new VmWorkResizeVolume(callingUser.getId(), callingAccount.getId(), vm.getId(),
@@ -2280,6 +2283,7 @@ public class VolumeApiServiceImpl extends ManagerBase implements VolumeApiServic
                 workJob.setStep(VmWorkJobVO.Step.Starting);
                 workJob.setVmType(vm.getType());
                 workJob.setVmInstanceId(vm.getId());
+                workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                 // save work context info (there are some duplications)
                 VmWorkMigrateVolume workInfo = new VmWorkMigrateVolume(callingUser.getId(), callingAccount.getId(), vm.getId(),
@@ -2324,6 +2328,7 @@ public class VolumeApiServiceImpl extends ManagerBase implements VolumeApiServic
                 workJob.setStep(VmWorkJobVO.Step.Starting);
                 workJob.setVmType(vm.getType());
                 workJob.setVmInstanceId(vm.getId());
+                workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                 // save work context info (there are some duplications)
                 VmWorkTakeVolumeSnapshot workInfo = new VmWorkTakeVolumeSnapshot(

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

@@ -830,6 +830,7 @@ public class VMSnapshotManagerImpl extends ManagerBase implements VMSnapshotMana
                 workJob.setStep(VmWorkJobVO.Step.Starting);
                 workJob.setVmType(vm.getType());
                 workJob.setVmInstanceId(vm.getId());
+                workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                 // save work context info (there are some duplications)
                 VmWorkCreateVMSnapshot workInfo = new VmWorkCreateVMSnapshot(callingUser.getId(), callingAccount.getId(), vm.getId(),
@@ -873,6 +874,7 @@ public class VMSnapshotManagerImpl extends ManagerBase implements VMSnapshotMana
                 workJob.setStep(VmWorkJobVO.Step.Starting);
                 workJob.setVmType(vm.getType());
                 workJob.setVmInstanceId(vm.getId());
+                workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                 // save work context info (there are some duplications)
                 VmWorkDeleteVMSnapshot workInfo = new VmWorkDeleteVMSnapshot(callingUser.getId(), callingAccount.getId(), vm.getId(),
@@ -916,6 +918,7 @@ public class VMSnapshotManagerImpl extends ManagerBase implements VMSnapshotMana
                 workJob.setStep(VmWorkJobVO.Step.Starting);
                 workJob.setVmType(vm.getType());
                 workJob.setVmInstanceId(vm.getId());
+                workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                 // save work context info (there are some duplications)
                 VmWorkRevertToVMSnapshot workInfo = new VmWorkRevertToVMSnapshot(callingUser.getId(), callingAccount.getId(), vm.getId(),
@@ -959,6 +962,7 @@ public class VMSnapshotManagerImpl extends ManagerBase implements VMSnapshotMana
                 workJob.setStep(VmWorkJobVO.Step.Starting);
                 workJob.setVmType(vm.getType());
                 workJob.setVmInstanceId(vm.getId());
+                workJob.setRelated(AsyncJobExecutionContext.getOriginJobContextId());
 
                 // save work context info (there are some duplications)
                 VmWorkDeleteAllVMSnapshots workInfo = new VmWorkDeleteAllVMSnapshots(callingUser.getId(), callingAccount.getId(), vm.getId(),