自动服务添加日志

examcloud-core-oe-task-service/src/main/java/cn/com/qmth/examcloud/core/oe/task/service/pipeline/AfterHandInExamExecutor.java

@@ -63,6 +63,8 @@ public class AfterHandInExamExecutor implements NodeExecuter<Long, ExamRecordDat
 
         String sequenceLockKey = Constants.EXAM_CONTROL_LOCK_PREFIX + examRecordData.getStudentId();
 
+        long st = System.currentTimeMillis();
+
         try {
             this.debugLog("enter executor...", examRecordData.getId());
 
@@ -117,6 +119,8 @@ public class AfterHandInExamExecutor implements NodeExecuter<Long, ExamRecordDat
                     "'.do nothing and go to the next node...", examRecordData.getId());
         } finally {
             SequenceLockHelper.releaseLockSimple(sequenceLockKey);
+            this.debugLog("T999 HandInExamExecutor合计耗时:" +
+                    (System.currentTimeMillis() - st) + " ms", examRecordData.getId());
         }
     }
 

examcloud-core-oe-task-service/src/main/java/cn/com/qmth/examcloud/core/oe/task/service/pipeline/ClearExamDataCacheExecutor.java

@@ -50,6 +50,8 @@ public class ClearExamDataCacheExecutor implements NodeExecuter<Long, ExamRecord
 
         String sequenceLockKey = Constants.EXAM_CONTROL_LOCK_PREFIX + examRecordData.getStudentId();
 
+        long st = System.currentTimeMillis();
+
         try {
             Long examRecordDataId = examRecordData.getId();
             debugLog("enter executor...", examRecordDataId);
@@ -99,6 +101,8 @@ public class ClearExamDataCacheExecutor implements NodeExecuter<Long, ExamRecord
 
         } finally {
             SequenceLockHelper.releaseLockSimple(sequenceLockKey);
+            this.debugLog("T999 ClearExamDataCacheExecutor合计耗时:" +
+                    (System.currentTimeMillis() - st) + " ms", examRecordData.getId());
         }
     }
 

examcloud-core-oe-task-service/src/main/java/cn/com/qmth/examcloud/core/oe/task/service/pipeline/HandInExamExecutor.java

@@ -7,6 +7,7 @@ import cn.com.qmth.examcloud.commons.helpers.pipeline.NodeExecuter;
 import cn.com.qmth.examcloud.commons.helpers.pipeline.TaskContext;
 import cn.com.qmth.examcloud.commons.logging.ExamCloudLog;
 import cn.com.qmth.examcloud.commons.logging.ExamCloudLogFactory;
+import cn.com.qmth.examcloud.commons.util.JsonUtil;
 import cn.com.qmth.examcloud.core.oe.student.api.ExamRecordDataCloudService;
 import cn.com.qmth.examcloud.core.oe.student.api.request.HandInExamReq;
 import cn.com.qmth.examcloud.core.oe.task.service.ExamRecordDataService;
@@ -84,6 +85,13 @@ public class HandInExamExecutor implements NodeExecuter<Long, ExamRecordData, Lo
 
                 ExamingSession examingSession = examingSessionService.getExamingSession(examRecordData.getStudentId());
 
+                if (null == examingSession) {
+                    this.debugLog("examingSession is null...", examRecordDataId);
+                } else {
+                    this.debugLog("examingSession is not null and the json is..." + JsonUtil.toJson(examingSession),
+                            examRecordDataId);
+                }
+
                 // 如果考试会话不存在/超过断点续考时间，自动交卷
                 if (null == examingSession || isOverBreakpointTime(examingSession)) {
 
@@ -180,6 +188,13 @@ public class HandInExamExecutor implements NodeExecuter<Long, ExamRecordData, Lo
         ExamingActivityTime examingActiveTime = redisClient.get(examingActiveTimeKey,
                 ExamingActivityTime.class);
 
+        if (null == examingActiveTime) {
+            this.debugLog("validating isOverBreakpointTime... and examingActiveTime is null...", examingSession.getExamRecordDataId());
+        } else {
+            this.debugLog("validating isOverBreakpointTime... and the json of examingActiveTime is..." + JsonUtil.toJson(examingActiveTime)
+                    , examingSession.getExamRecordDataId());
+        }
+
         long activeTime = null == examingActiveTime
                 ? System.currentTimeMillis()
                 : examingActiveTime.getActiveTime();

examcloud-core-oe-task-service/src/main/java/cn/com/qmth/examcloud/core/oe/task/service/pipeline/SyncExamDataExecutor.java

@@ -81,6 +81,8 @@ public class SyncExamDataExecutor implements NodeExecuter<Long, ExamRecordData,
         Long studentId = examRecordData.getStudentId();
         String sequenceLockKey = Constants.EXAM_CONTROL_LOCK_PREFIX + studentId;
 
+        long st = System.currentTimeMillis();
+
         try {
             debugLog("enter executor...", examRecordData.getId());
 
@@ -103,11 +105,13 @@ public class SyncExamDataExecutor implements NodeExecuter<Long, ExamRecordData,
             Long examRecordDataId = examRecordData.getId();
             if (ExamRecordStatus.EXAM_HAND_IN == examRecordData.getExamRecordStatus() ||
                     ExamRecordStatus.EXAM_AUTO_HAND_IN == examRecordData.getExamRecordStatus()) {
-                this.debugLog("prepare to execute last node's hand in data...", examRecordDataId);
 
+                this.debugLog("prepare to execute last node's hand in data...", examRecordDataId);
+                long startTime = System.currentTimeMillis();
                 examRecordData = examRecordDataService.processAfterHandInExam(examRecordDataId);
 
-                this.debugLog("execute last node's hand in data success...", examRecordDataId);
+                this.debugLog("T001.execute last node's hand in data success...耗时：" +
+                        (System.currentTimeMillis() - startTime) + " ms", examRecordDataId);
             }
 
             //如果考试记录状态为完结状态，则开始同步数据到正式库
@@ -144,7 +148,7 @@ public class SyncExamDataExecutor implements NodeExecuter<Long, ExamRecordData,
                 //同步数据
                 syncExamDataCloudService.syncExamData(syncReq);
 
-                this.debugLog("999 同步数据rpc共计耗时:" + (System.currentTimeMillis() - startTime) + " ms",examRecordDataId);
+                this.debugLog("T002.同步数据rpc耗时:" + (System.currentTimeMillis() - startTime) + " ms", examRecordDataId);
 
                 this.debugLog("sync data success,and to be change status...", examRecordDataId);
 
@@ -153,12 +157,21 @@ public class SyncExamDataExecutor implements NodeExecuter<Long, ExamRecordData,
                 if (null != examBoss) {
                     examBoss.setEndCount(examBoss.getEndCount() + 1);
 
+                    startTime = System.currentTimeMillis();
+
                     examBossService.saveExamBoss(examRecordData.getExamStudentId(), examBoss);
+
+                    this.debugLog("T003.考试完结次数加1,并saveExamBoss耗时..." +
+                            (System.currentTimeMillis() - startTime) + " ms", examRecordDataId);
                 }
 
                 //设置并保存考试记录的同步状态
+                startTime = System.currentTimeMillis();
+
                 examRecordData.setSyncStatus(SyncStatus.SYNCED);
                 setAndSaveExamRecordDataSyncStatus(examRecordDataId);
+                this.debugLog("T004.设置并保存考试记录的同步状态,耗时..." +
+                        (System.currentTimeMillis() - startTime) + " ms", examRecordDataId);
 
                 outList.add(new KeyValuePair<>(key, examRecordData));
 
@@ -174,6 +187,7 @@ public class SyncExamDataExecutor implements NodeExecuter<Long, ExamRecordData,
                     "'.do nothing and go to the next node...", examRecordData.getId());
         } finally {
             SequenceLockHelper.releaseLockSimple(sequenceLockKey);
+            this.debugLog("T999 同步数据合计耗时:" + (System.currentTimeMillis() - st) + " ms", examRecordData.getId());
         }
     }
 
@@ -318,7 +332,7 @@ public class SyncExamDataExecutor implements NodeExecuter<Long, ExamRecordData,
             return new ArrayList<>();
         }
 
-        debugLog("the result joson of method getExamFaceLivenessVerifies is :"+ JsonUtil.toJson(resp),examRecordDataId);
+        debugLog("the result joson of method getExamFaceLivenessVerifies is :" + JsonUtil.toJson(resp), examRecordDataId);
 
         List<ExamFaceLivenessVerifyBean> resultList = new ArrayList<>();
         for (cn.com.qmth.examcloud.core.oe.student.api.bean.ExamFaceLivenessVerifyBean eflvb : resp.getExamFaceLivenessVerifis()) {