流式任务添加日志

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

@@ -4,6 +4,8 @@ import cn.com.qmth.examcloud.commons.exception.StatusException;
 import cn.com.qmth.examcloud.commons.helpers.KeyValuePair;
 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.core.oe.student.api.ExamRecordDataCloudService;
 import cn.com.qmth.examcloud.core.oe.student.api.request.CalcExamScoreReq;
 import cn.com.qmth.examcloud.core.oe.student.api.request.CalcFaceBiopsyResultReq;
@@ -38,6 +40,9 @@ public class AfterHandInExamExecutor implements NodeExecuter<Long, ExamRecordDat
     @Autowired
     private ExamRecordDataService examRecordDataService;
     private static Long DEFAULT_MAX_PROCESS_SECONDS = 30L;
+    @Autowired
+    private static final ExamCloudLog LOG = ExamCloudLogFactory.getLog(AfterHandInExamExecutor.class);
+
 
     /**
      * 执行
@@ -58,13 +63,19 @@ public class AfterHandInExamExecutor implements NodeExecuter<Long, ExamRecordDat
         String sequenceLockKey = Constants.EXAM_CONTROL_LOCK_PREFIX + examRecordData.getStudentId();
 
         try {
+            this.debugLog("enter executor...", examRecordData.getId());
+
             //添加考试控制全局锁
             SequenceLockHelper.getLockSimple(sequenceLockKey);
 
+            this.debugLog("get locker success...", examRecordData.getId());
+
             //针对已交卷的数据进行交卷后续处理
             if (examRecordData.getExamRecordStatus() == ExamRecordStatus.EXAM_HAND_IN ||
                     examRecordData.getExamRecordStatus() == ExamRecordStatus.EXAM_AUTO_HAND_IN) {
 
+                this.debugLog("prepare to execute after hand in ...", examRecordData.getId());
+
                 SysPropertyCacheBean maxProcessSecondsProperty = CacheHelper.getSysProperty("oe.task.maxProcessSeconds");
                 //本节点最大处理时长
                 Long maxProcessSeconds;
@@ -83,6 +94,9 @@ public class AfterHandInExamExecutor implements NodeExecuter<Long, ExamRecordDat
                 //如果交卷后超过指定时长内仍未处理完成，则交给下一节点进行处理
                 if (times > maxProcessSeconds * 1000) {
                     outList.add(new KeyValuePair<>(key, examRecordData));
+
+                    this.debugLog("not complete in time and will retry in next node...", examRecordData.getId());
+
                     return;
                 }
 
@@ -90,13 +104,24 @@ public class AfterHandInExamExecutor implements NodeExecuter<Long, ExamRecordDat
 
                 outList.add(new KeyValuePair<>(key, examRecordData));
 
+                this.debugLog("after hand in success..", examRecordData.getId());
+
                 return;
             }
 
             //其它状态数据，直接交给下一步
             outList.add(new KeyValuePair<>(key, examRecordData));
+
+            this.debugLog("current status is '" + examRecordData.getExamRecordStatus().name() +
+                    "'.do nothing and go to the next node...", examRecordData.getId());
         } finally {
             SequenceLockHelper.releaseLockSimple(sequenceLockKey);
         }
     }
+
+    private void debugLog(String msg, Long examRecordDataId) {
+        if (LOG.isDebugEnabled()) {
+            LOG.debug("[AFTER-HAND-IN-EXAM-EXECUTOR-" + examRecordDataId + "]：" + msg);
+        }
+    }
 }

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

@@ -3,6 +3,8 @@ package cn.com.qmth.examcloud.core.oe.task.service.pipeline;
 import cn.com.qmth.examcloud.commons.helpers.KeyValuePair;
 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.core.oe.task.service.ExamBossService;
 import cn.com.qmth.examcloud.support.Constants;
 import cn.com.qmth.examcloud.support.enums.SyncStatus;
@@ -25,6 +27,7 @@ public class ClearExamDataCacheExecutor implements NodeExecuter<Long, ExamRecord
 
     @Autowired
     private ExamBossService examBossService;
+    private static final ExamCloudLog LOG = ExamCloudLogFactory.getLog(ClearExamDataCacheExecutor.class);
 
     /**
      * 执行
@@ -45,14 +48,26 @@ public class ClearExamDataCacheExecutor implements NodeExecuter<Long, ExamRecord
         String sequenceLockKey = Constants.EXAM_CONTROL_LOCK_PREFIX + examRecordData.getStudentId();
 
         try {
+            debugLog("enter executor...", examRecordData.getId());
+
             //添加考试控制全局锁
             SequenceLockHelper.getLockSimple(sequenceLockKey);
 
+            debugLog("get locker success...", examRecordData.getId());
+
             //只有已同步成功的数据，才执行清理操作
             if (SyncStatus.SYNCED == examRecordData.getSyncStatus()) {
+
                 clearExamCache(examRecordData.getExamStudentId());
+
+                this.debugLog("all is over.", examRecordData.getId());
+
+                return;
             }
 
+            this.debugLog("current status is '" + examRecordData.getExamRecordStatus().name() +
+                    "'.may be redundant data.", examRecordData.getId());
+
         } finally {
             SequenceLockHelper.releaseLockSimple(sequenceLockKey);
         }
@@ -76,4 +91,9 @@ public class ClearExamDataCacheExecutor implements NodeExecuter<Long, ExamRecord
         }
     }
 
+    private void debugLog(String msg, Long examRecordDataId) {
+        if (LOG.isDebugEnabled()) {
+            LOG.debug("[CLEAR-EXAM-DATA-CACHE-EXECUTOR-" + examRecordDataId + "]：" + msg);
+        }
+    }
 }

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

@@ -5,6 +5,9 @@ import java.util.Date;
 import java.util.List;
 
 import cn.com.qmth.examcloud.commons.exception.StatusException;
+import cn.com.qmth.examcloud.commons.helpers.pipeline.SimpleNode;
+import cn.com.qmth.examcloud.commons.logging.ExamCloudLog;
+import cn.com.qmth.examcloud.commons.logging.ExamCloudLogFactory;
 import org.springframework.beans.factory.annotation.Autowired;
 import org.springframework.stereotype.Component;
 
@@ -38,6 +41,8 @@ public class HandInExamExecutor implements NodeExecuter<Long, ExamRecordData, Lo
     private ExamRecordDataService examRecordDataService;
     @Autowired
     private RedisClient redisClient;
+    @Autowired
+    private static final ExamCloudLog LOG = ExamCloudLogFactory.getLog(HandInExamExecutor.class);
 
     /**
      * 执行
@@ -58,9 +63,14 @@ public class HandInExamExecutor implements NodeExecuter<Long, ExamRecordData, Lo
         String sequenceLockKey = Constants.EXAM_CONTROL_LOCK_PREFIX + examRecordData.getStudentId();
 
         try {
+
+            this.debugLog("enter executor...", examRecordData.getId());
+
             //添加考试控制全局锁
             SequenceLockHelper.getLockSimple(sequenceLockKey);
 
+            this.debugLog("get locker success...", examRecordData.getId());
+
             //获取最新的考试记录状态
             ExamRecordData examRecordDataCache = examRecordDataService.getExamRecordDataCache(examRecordData.getId());
 
@@ -75,6 +85,9 @@ public class HandInExamExecutor implements NodeExecuter<Long, ExamRecordData, Lo
                 if (null == examingSession || isOverExamTime(examingSession) || isOverBreakpointTime(examingSession)) {
 
                     try {
+
+                        this.debugLog("prepare to auto hand in...", examRecordData.getId());
+
                         //更改内存中的交卷状态
                         examRecordData.setExamRecordStatus(ExamRecordStatus.EXAM_AUTO_HAND_IN);
                         examRecordData.setCleanTime(new Date());
@@ -87,6 +100,11 @@ public class HandInExamExecutor implements NodeExecuter<Long, ExamRecordData, Lo
                         }
 
                         outList.add(new KeyValuePair<>(key, examRecordData));
+
+                        this.debugLog("auto hand in success...", examRecordData.getId());
+
+                        return;
+
                     } catch (Exception e) {
                         //回滚自动交卷操作
                         examRecordData.setExamRecordStatus(ExamRecordStatus.EXAM_ING);
@@ -96,20 +114,26 @@ public class HandInExamExecutor implements NodeExecuter<Long, ExamRecordData, Lo
                         outList.clear();
                         removable = false;
 
+                        this.errorLog("auto hand in occurs error,to be retry...", e, examRecordData.getId());
+
                         throw new StatusException("300101", "自动交卷出现异常：" + e.getMessage());
                     }
-
-                    return;
                 }
 
                 //如果不需要自动交卷，则需要下次轮循，继续处理
                 removable = false;
                 outList.clear();
+
+                this.debugLog("don't need auto hand in.to be retry...", examRecordData.getId());
+
                 return;
             }
 
             //其它状态的数据，直接交给下一个节点处理
             outList.add(new KeyValuePair<>(key, examRecordData));
+
+            this.debugLog("current status is '" + examRecordData.getExamRecordStatus().name() +
+                    "'.do nothing and go to the next node...", examRecordData.getId());
         } finally {
             SequenceLockHelper.releaseLockSimple(sequenceLockKey);
         }
@@ -152,4 +176,16 @@ public class HandInExamExecutor implements NodeExecuter<Long, ExamRecordData, Lo
         return now - activeTime >= examingSession.getExamReconnectTime().intValue() * 60 * 1000;
     }
 
+    private void debugLog(String msg, Long examRecordDataId) {
+        if (LOG.isDebugEnabled()) {
+            LOG.debug("[HAND-IN-EXAM-EXECUTOR-" + examRecordDataId + "]：" + msg);
+        }
+    }
+
+    private void errorLog(String msg, Exception e, Long examRecordDataId) {
+        if (LOG.isErrorEnabled()) {
+            LOG.error("[HAND-IN-EXAM-EXECUTOR-" + examRecordDataId + "]：" + msg, e);
+        }
+    }
+
 }

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

@@ -3,6 +3,8 @@ package cn.com.qmth.examcloud.core.oe.task.service.pipeline;
 import cn.com.qmth.examcloud.commons.helpers.KeyValuePair;
 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.core.oe.admin.api.SyncExamDataCloudService;
 import cn.com.qmth.examcloud.core.oe.admin.api.bean.*;
 import cn.com.qmth.examcloud.core.oe.admin.api.request.SyncExamDataReq;
@@ -56,7 +58,7 @@ public class SyncExamDataExecutor implements NodeExecuter<Long, ExamRecordData,
     private ExamRecordDataCloudService examRecordDataCloudService;
     @Autowired
     private ExamBossService examBossService;
-
+    private static final ExamCloudLog LOG = ExamCloudLogFactory.getLog(SyncExamDataExecutor.class);
 
     /**
      * 执行
@@ -78,13 +80,20 @@ public class SyncExamDataExecutor implements NodeExecuter<Long, ExamRecordData,
         String sequenceLockKey = Constants.EXAM_CONTROL_LOCK_PREFIX + studentId;
 
         try {
+            debugLog("enter executor...",examRecordData.getId());
+
             //添加考试控制全局锁
             SequenceLockHelper.getLockSimple(sequenceLockKey);
 
+            debugLog("get locker success...",examRecordData.getId());
+
             //如果已同步，直接交给下一节点
             if (SyncStatus.SYNCED == examRecordData.getSyncStatus()) {
+
                 outList.add(new KeyValuePair<>(key, examRecordData));
 
+                this.debugLog("already synced,will go to next node...",examRecordData.getId());
+
                 return;
             }
 
@@ -92,13 +101,19 @@ 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);
+
                 examRecordDataService.processAfterHandInExam(examRecordDataId);
+
+                this.debugLog("execute last node's hand in data success...",examRecordDataId);
             }
 
             //如果考试记录状态为完结状态，则开始同步数据到正式库
             if (ExamRecordStatus.EXAM_END == examRecordData.getExamRecordStatus() ||
                     ExamRecordStatus.EXAM_OVERDUE == examRecordData.getExamRecordStatus()) {
 
+                this.debugLog("prepare to sync data...",examRecordDataId);
+
                 //同步数据
                 SyncExamDataReq syncReq = new SyncExamDataReq();
                 syncReq.setExamRecordData(copyExamRecordDataFrom(examRecordData));
@@ -120,6 +135,8 @@ public class SyncExamDataExecutor implements NodeExecuter<Long, ExamRecordData,
 
                 syncExamDataCloudService.syncExamData(syncReq);
 
+                this.debugLog("sync data success,and to be change status...",examRecordDataId);
+
                 //考试完结次数加1
                 ExamBoss examBoss = examBossService.getExamBoss(examRecordData.getExamStudentId());
                 if (null != examBoss) {
@@ -132,12 +149,16 @@ public class SyncExamDataExecutor implements NodeExecuter<Long, ExamRecordData,
 
                 outList.add(new KeyValuePair<>(key, examRecordData));
 
+                this.debugLog("sync data and change status success...",examRecordDataId);
+
                 return;
             }
 
             //其它状态的数据，直接交给下一个节点处理
             outList.add(new KeyValuePair<>(key, examRecordData));
 
+            this.debugLog("current status is '" + examRecordData.getExamRecordStatus().name() +
+                    "'.do nothing and go to the next node...", examRecordData.getId());
         } finally {
             SequenceLockHelper.releaseLockSimple(sequenceLockKey);
         }
@@ -385,4 +406,10 @@ public class SyncExamDataExecutor implements NodeExecuter<Long, ExamRecordData,
         examRecordData.setSyncStatus(SyncStatus.SYNCED);
         examRecordDataService.saveExamRecordDataCache(examRecordDataId, examRecordData);
     }
+
+    private void debugLog(String msg,Long examRecordDataId) {
+        if (LOG.isDebugEnabled()) {
+            LOG.debug("[SYNC-EXAM-DATA-EXECUTOR-" + examRecordDataId + "]："+msg);
+        }
+    }
 }

examcloud-core-oe-task-starter/src/main/resources/log4j2.xml

@@ -55,6 +55,38 @@
 				</Delete>
 			</DefaultRolloverStrategy>
 		</RollingFile>
+
+		<!-- 流式自动服务综合 日志 -->
+		<RollingFile name="ROOT_STREAM_TASK_APPENDER" fileName="./logs/stream/root-stream.log" filePattern="./logs/stream/root-stream-%d{yyyy.MM.dd.HH}-%i.log">
+			<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS}| %level | %X{TRACE_ID} - %X{CALLER} | %m | %l%n" />
+			<Policies>
+				<TimeBasedTriggeringPolicy interval="1" />
+				<SizeBasedTriggeringPolicy size="100MB" />
+			</Policies>
+			<DefaultRolloverStrategy max="10000">
+				<Delete basePath="./logs/stream" maxDepth="1">
+					<IfFileName glob="root-stream-*.log">
+						<IfAccumulatedFileSize exceeds="2 GB" />
+					</IfFileName>
+				</Delete>
+			</DefaultRolloverStrategy>
+		</RollingFile>
+
+		<!-- 流式自动服务详细 日志 -->
+		<RollingFile name="NODE_STREAM_TASK_APPENDER" fileName="./logs/stream/node-stream.log" filePattern="./logs/stream/node-stream-%d{yyyy.MM.dd.HH}-%i.log">
+			<PatternLayout pattern="%d{yyyy-MM-dd HH:mm:ss.SSS}| %level | %X{TRACE_ID} - %X{CALLER} | %m | %l%n" />
+			<Policies>
+				<TimeBasedTriggeringPolicy interval="1" />
+				<SizeBasedTriggeringPolicy size="100MB" />
+			</Policies>
+			<DefaultRolloverStrategy max="10000">
+				<Delete basePath="./logs/stream" maxDepth="1">
+					<IfFileName glob="node-stream-*.log">
+						<IfAccumulatedFileSize exceeds="2 GB" />
+					</IfFileName>
+				</Delete>
+			</DefaultRolloverStrategy>
+		</RollingFile>
 	</Appenders>
 
 	<Loggers>
@@ -88,6 +120,16 @@
 			<AppenderRef ref="Console" />
 		</Logger>
 
+		<Logger name="cn.com.qmth.examcloud.commons.helpers.pipeline" level="DEBUG" additivity="false">
+			<AppenderRef ref="ROOT_STREAM_TASK_APPENDER" />
+			<AppenderRef ref="Console" />
+		</Logger>
+
+		<Logger name="cn.com.qmth.examcloud.core.oe.task.service.pipeline" level="DEBUG" additivity="false">
+			<AppenderRef ref="NODE_STREAM_TASK_APPENDER" />
+			<AppenderRef ref="Console" />
+		</Logger>
+
 		<Logger name="org.hibernate.type.descriptor.sql.BasicBinder" level="${commonLevel}" />
 		<Logger name="org.hibernate.type.descriptor.sql.BasicExtractor" level="${commonLevel}" />
 		<Logger name="org.hibernate.SQL" level="${commonLevel}" />