shjung 11 months ago
parent
commit
fa478f68e9

+ 69 - 0
src/main/java/com/its/rota/server/aspect/LoggingAspect.java

@@ -0,0 +1,69 @@
+package com.its.rota.server.aspect;
+
+import com.its.app.common.utils.Elapsed;
+import com.its.rota.server.entity.TbSndLog;
+import com.its.rota.server.process.dbms.DbmsData;
+import lombok.extern.slf4j.Slf4j;
+import org.aspectj.lang.ProceedingJoinPoint;
+import org.aspectj.lang.annotation.Around;
+import org.aspectj.lang.annotation.Aspect;
+import org.springframework.stereotype.Component;
+
+@Slf4j
+@Aspect
+@Component
+public class LoggingAspect {
+    @Around("@annotation(com.its.rota.server.aspect.annotation.ScheduleElapsed)")
+    public Object scheduleElapsedTime(ProceedingJoinPoint joinPoint) throws Throwable {
+
+        String proceedName = String.format("%45s", joinPoint.getTarget().getClass().getSimpleName() + "." + joinPoint.getSignature().getName());
+        Elapsed elapsed = new Elapsed();
+        Object proceed = joinPoint.proceed();
+        log.info("{}: {}", proceedName, Elapsed.elapsedTimeStr(elapsed.nanoSeconds()));
+        return proceed;
+    }
+    @Around("@annotation(com.its.rota.server.aspect.annotation.ProcessElapsed)")
+    public Object processElapsedTime(ProceedingJoinPoint joinPoint) throws Throwable {
+        String proceedName = String.format("%45s", joinPoint.getTarget().getClass().getSimpleName() + "." + joinPoint.getSignature().getName());
+        Elapsed elapsed = new Elapsed();
+        Object proceed = joinPoint.proceed();
+        log.info("{}: {}", proceedName, Elapsed.elapsedTimeStr(elapsed.nanoSeconds()));
+        return proceed;
+    }
+    @Around("@annotation(com.its.rota.server.aspect.annotation.DbmsElapsed)")
+    public Object dbmsElapsedTime(ProceedingJoinPoint joinPoint) throws Throwable {
+        Object[] params = joinPoint.getArgs();
+        DbmsData dbmsData = null;
+        if (params.length > 0) {
+            if (params[0] instanceof DbmsData) {
+                dbmsData = (DbmsData) params[0];
+            }
+        }
+
+        String proceedName = String.format("%45s", joinPoint.getTarget().getClass().getSimpleName() + "." + joinPoint.getSignature().getName());
+        Elapsed elapsed = new Elapsed();
+        Object proceed = joinPoint.proceed();
+        if (dbmsData != null) {
+            switch(dbmsData.getType()) {
+                case DbmsData.DBMS_DATA_SND_LOG_INCIDENT:
+                    log.info("{}: DBMS_DATA_SND_LOG_INCIDENT, {}", proceedName, Elapsed.elapsedTimeStr(elapsed.nanoSeconds()));
+                    break;
+                case DbmsData.DBMS_DATA_SND_LOG_TRAFFIC:
+                    TbSndLog trfLog = (TbSndLog) dbmsData.getData();
+                    log.info("{}: DBMS_DATA_SND_LOG_TRAFFIC, {} EA. {}", proceedName, trfLog.getDataCnt(), Elapsed.elapsedTimeStr(elapsed.nanoSeconds()));
+                    break;
+                case DbmsData.DBMS_DATA_DELETE_SND_LOG:
+                    log.info("{}: DBMS_DATA_DELETE_SND_LOG, {}", proceedName, Elapsed.elapsedTimeStr(elapsed.nanoSeconds()));
+                    break;
+                case DbmsData.DBMS_DATA_DELETE_SND_INCIDENT:
+                    log.info("{}: DBMS_DATA_DELETE_SND_INCIDENT, {}", proceedName, Elapsed.elapsedTimeStr(elapsed.nanoSeconds()));
+                    break;
+                default:
+            }
+        }
+        else {
+            log.info("{}: {}", proceedName, Elapsed.elapsedTimeStr(elapsed.nanoSeconds()));
+        }
+        return proceed;
+    }
+}

+ 4 - 0
src/main/java/com/its/rota/server/aspect/annotation/DbmsElapsed.java

@@ -0,0 +1,4 @@
+package com.its.rota.server.aspect.annotation;
+
+public @interface DbmsElapsed {
+}

+ 4 - 0
src/main/java/com/its/rota/server/aspect/annotation/ProcessElapsed.java

@@ -0,0 +1,4 @@
+package com.its.rota.server.aspect.annotation;
+
+public @interface ProcessElapsed {
+}

+ 4 - 0
src/main/java/com/its/rota/server/aspect/annotation/ScheduleElapsed.java

@@ -0,0 +1,4 @@
+package com.its.rota.server.aspect.annotation;
+
+public @interface ScheduleElapsed {
+}

+ 2 - 0
src/main/java/com/its/rota/server/process/dbms/DbmsDataProcess.java

@@ -1,6 +1,7 @@
 package com.its.rota.server.process.dbms;
 
 import com.its.app.common.utils.Elapsed;
+import com.its.rota.server.aspect.annotation.DbmsElapsed;
 import com.its.rota.server.common.SpringUtils;
 import com.its.rota.server.config.ThreadPoolInitializer;
 import com.its.rota.server.dao.mapper.IncidentMapper;
@@ -60,6 +61,7 @@ public class DbmsDataProcess {
         process(data);
     }
 
+    @DbmsElapsed
     public void process(DbmsData data) {
         int type = data.getType();
         int result = 0;

+ 5 - 0
src/main/java/com/its/rota/server/scheduler/ApplicationScheduler.java

@@ -1,5 +1,6 @@
 package com.its.rota.server.scheduler;
 
+import com.its.rota.server.aspect.annotation.ScheduleElapsed;
 import com.its.rota.server.config.SchedulingConfig;
 import com.its.rota.server.process.dbms.DbmsData;
 import com.its.rota.server.process.dbms.DbmsDataProcess;
@@ -37,6 +38,7 @@ public class ApplicationScheduler {
 //    public void unitSystSchedule() {
 //    }
 
+    @ScheduleElapsed
     @Async
     @Scheduled(cron = "${application.scheduler.delete-snd-incident:0/40 3 * * * *}")
     public void deleteSndIncident() {
@@ -52,6 +54,7 @@ public class ApplicationScheduler {
         }
     }
 
+    @ScheduleElapsed
     @Async
     @Scheduled(cron = "${application.scheduler.delete-snd-log:0/40 3 * * * *}")
     public void deleteSndLog() {
@@ -67,6 +70,7 @@ public class ApplicationScheduler {
         }
     }
 
+    @ScheduleElapsed
     @Async
     @Scheduled(cron = "0 * * * * *")  // 1분 주기 작업 실행
     public void checkSendIncident() {
@@ -78,6 +82,7 @@ public class ApplicationScheduler {
         }
     }
 
+    @ScheduleElapsed
     @Async
     @Scheduled(cron = "0/10 * * * * *")  // 10초 주기 작업 실행
     public void checkSendTraffic() {

+ 16 - 13
src/main/java/com/its/rota/server/service/ItsRotaServerService.java

@@ -1,6 +1,7 @@
 package com.its.rota.server.service;
 
 import com.its.app.common.utils.Elapsed;
+import com.its.rota.server.aspect.annotation.ProcessElapsed;
 import com.its.rota.server.dao.mapper.IncidentMapper;
 import com.its.rota.server.dao.mapper.TrafficMapper;
 import com.its.rota.server.dto.CenterDto;
@@ -59,24 +60,25 @@ public class ItsRotaServerService {
     }
 
     public int checkSendTraffic() {
+        String proceedName = String.format("%45s", this.getClass().getSimpleName() + ".checkSendTraffic");
         if (this.isRunning) {
-            log.warn("ItsRotaServerService.checkSendTraffic: Already running");
+            log.warn("{}: Already running.", proceedName);
             return 1;
         }
         Elapsed elapsed = new Elapsed();
         this.isRunning = true;
-        log.info("ItsRotaServerService.checkSendTraffic: start.");
+        log.info("{}: start.", proceedName);
         try {
             Elapsed elapsed1 = new Elapsed();
             List<TbCheckTraffic> result = this.mapper.selCheckTraffic();
             if (!result.isEmpty()) {
                 String trafficTime = result.get(0).getRegDate();
-                log.info("ItsRotaServerService.checkSendTraffic: checkTrafficTime: {}, currTrafficTime: {}.", ApplicationRepository.checkTrafficTime, trafficTime);
+                log.info("{}: checkTrafficTime: {}, currTrafficTime: {}.", proceedName, ApplicationRepository.checkTrafficTime, trafficTime);
                 if (!ApplicationRepository.checkTrafficTime.equals(trafficTime)) {
                     resetCenterTrafficSend();
                     elapsed1.reset();
                     List<TbTrafficCenter> traffics = this.mapper.selTrafficCenter();
-                    log.info("ItsRotaServerService.selTrafficCenter: {} EA. {}", traffics.size(), Elapsed.elapsedTimeStr(elapsed1.nanoSeconds()));
+                    log.info("{}: {} EA. {}", proceedName, traffics.size(), Elapsed.elapsedTimeStr(elapsed1.nanoSeconds()));
                     ApplicationRepository.checkTrafficTime = trafficTime;
 
                     ApplicationRepository.traffics = traffics;
@@ -94,26 +96,27 @@ public class ItsRotaServerService {
             }
         }
         catch (Exception e) {
-            log.error("ItsRotaServerService.checkSendTraffic: Exception {}", e.getMessage());
+            log.error("{}: Exception {}", proceedName, e.getMessage());
         }
         this.isRunning = false;
-        log.info("ItsRotaServerService.checkSendTraffic: ..end. {}", Elapsed.elapsedTimeStr(elapsed.nanoSeconds()));
+        log.info("{}: ..end. {}", proceedName, Elapsed.elapsedTimeStr(elapsed.nanoSeconds()));
         return 0;
     }
 
     public int checkSendIncident() {
+        String proceedName = String.format("%45s", this.getClass().getSimpleName() + ".checkSendIncident");
         if (this.isRunningCheckIncident) {
-            log.warn("ItsRotaServerService.checkSendIncident: Already running");
+            log.warn("{}: Already running.", proceedName);
             return 1;
         }
         Elapsed elapsed = new Elapsed();
         this.isRunningCheckIncident = true;
-        log.info("ItsRotaServerService.checkSendIncident: start.");
+        log.info("{}: start.", proceedName);
         try {
             Elapsed elapsed1 = new Elapsed();
             int deletes = this.incidentMapper.delCheckIncident();
             if (deletes > 0) {
-                log.info("ItsRotaServerService.checkSendIncident: delCheckIncident {} EA. {}", deletes, Elapsed.elapsedTimeStr(elapsed1.nanoSeconds()));
+                log.info("{}: delCheckIncident {} EA. {}", proceedName, deletes, Elapsed.elapsedTimeStr(elapsed1.nanoSeconds()));
             }
 
             long baseTime = System.currentTimeMillis();
@@ -133,7 +136,7 @@ public class ItsRotaServerService {
                 elapsed1.reset();
                 int inserts = this.incidentMapper.insSndIncident(incident);
                 if (inserts > 0) {
-                    log.info("ItsRotaServerService.checkSendIncident: insSndIncident {}, {} EA. {}", center.getCenterId(), inserts, Elapsed.elapsedTimeStr(elapsed1.nanoSeconds()));
+                    log.info("{}: insSndIncident {}, {} EA. {}", proceedName, center.getCenterId(), inserts, Elapsed.elapsedTimeStr(elapsed1.nanoSeconds()));
                 }
                 // 지역센터에 전송할 돌발정보를 메모리에 저장하고 지역센터에 전송하여야 한다.
                 List<TbSndIncident> result = this.incidentMapper.selSndIncident(incident);
@@ -171,16 +174,16 @@ public class ItsRotaServerService {
 
                 center.getIncident().init(baseTime, result);
                 if (!result.isEmpty()) {
-                    log.info("ItsRotaServerService.checkSendIncident: selSndIncident {}, {} EA. {}", center.getCenterId(), result.size(), Elapsed.elapsedTimeStr(elapsed1.nanoSeconds()));
+                    log.info("{}: selSndIncident {}, {} EA. {}", proceedName, center.getCenterId(), result.size(), Elapsed.elapsedTimeStr(elapsed1.nanoSeconds()));
                     center.executeSendIncident();
                 }
             }
         }
         catch (Exception e) {
-            log.error("ItsRotaServerService.checkSendIncident: Exception {}", e.getMessage());
+            log.error("{}: Exception {}", proceedName, e.getMessage());
         }
         this.isRunningCheckIncident = false;
-        log.info("ItsRotaServerService.checkSendIncident: ..end. {}", Elapsed.elapsedTimeStr(elapsed.nanoSeconds()));
+        log.info("{}: ..end. {}", proceedName, Elapsed.elapsedTimeStr(elapsed.nanoSeconds()));
         return 0;
     }
 

+ 2 - 3
src/main/java/com/its/rota/server/xnet/server/process/request/AiPublicationIncidentCondition.java

@@ -16,13 +16,12 @@ public class AiPublicationIncidentCondition {
     public static boolean run(CenterDto center) {
         boolean result;
         try {
-            MDC.put("id", center.getLogKey());
-            log.info("AiPublicationIncidentCondition.run: [{}, {}].", center.getLogKey(), center.getIpAddress());
-
             IncidentConditionsList lists = center.getIncidentConditionsList();
             if (lists.getIncidentConditions().isEmpty()) {
                 return true;
             }
+            MDC.put("id", center.getLogKey());
+            log.info("AiPublicationIncidentCondition.run: [{}, {}].", center.getLogKey(), center.getIpAddress());
 
             EndApplicationMessage endMsg =  new EndApplicationMessage();
             int[] messageId = {1, 0, 14827, 1, 1, 4};

+ 2 - 3
src/main/java/com/its/rota/server/xnet/server/process/request/AiPublicationTraffic.java

@@ -16,13 +16,12 @@ public class AiPublicationTraffic {
     public static boolean run(CenterDto center) {
         boolean result;
         try {
-            MDC.put("id", center.getLogKey());
-            log.info("AiPublicationTraffic.run: [{}, {}].", center.getLogKey(), center.getIpAddress());
-
             CurrentLinkStateList lists = center.getCurrentLinkStateList();
             if (lists.getCurrentLinkState().isEmpty()) {
                 return true;
             }
+            MDC.put("id", center.getLogKey());
+            log.info("AiPublicationTraffic.run: [{}, {}].", center.getLogKey(), center.getIpAddress());
 
             EndApplicationMessage endMsg =  new EndApplicationMessage();
             int[] messageId = {1, 0, 14827, 1, 1, 1};

+ 13 - 0
src/main/resources/logback-spring-appender.xml

@@ -42,6 +42,19 @@
         </rollingPolicy>
     </appender>
 
+    <appender name="FILE_ASPECT" class="ch.qos.logback.core.rolling.RollingFileAppender">
+        <file>${LOG_PATH}${LOG_FILE_NAME_ASPECT}</file>
+        <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
+            <charset>${LOG_CHARSET}</charset>
+            <pattern>${LOG_PATTERN_ASPECT}</pattern>
+        </encoder>
+        <rollingPolicy class="ch.qos.logback.core.rolling.SizeAndTimeBasedRollingPolicy">
+            <fileNamePattern>${LOG_BACKUP_PATH}${LOG_FILE_ASPECT}.${LOG_FILE_NAME_PATTERN}</fileNamePattern>
+            <maxFileSize>${MAX_FILESIZE}</maxFileSize>
+            <maxHistory>${MAX_HISTORY}</maxHistory>
+        </rollingPolicy>
+    </appender>
+
     <appender name="FILE_ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">
         <filter class="ch.qos.logback.classic.filter.LevelFilter">
             <level>error</level>

+ 12 - 12
src/main/resources/logback-spring.xml

@@ -17,7 +17,7 @@
     <property name="LOG_FILE_NAME_SESSION"     value="${PROJECT_PREFIX}-session.log"/>
     <property name="LOG_FILE_NAME_SQL"         value="${PROJECT_PREFIX}-sql.log"/>
     <property name="LOG_FILE_NAME_SCHEDULE"    value="${PROJECT_PREFIX}-schedule.log"/>
-    <property name="LOG_FILE_NAME_STATISTICS"  value="${PROJECT_PREFIX}-statistics.log"/>
+    <property name="LOG_FILE_NAME_ASPECT"      value="${PROJECT_PREFIX}-aspect.log"/>
 
     <property name="MAX_FILESIZE" value="10MB"/>
     <property name="MAX_HISTORY"  value="10"/>
@@ -27,8 +27,7 @@
     <property name="LOG_PATTERN_SESSION"     value="[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%-5level] %msg%n"/>
     <property name="LOG_PATTERN_SQL"         value="[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%-5level] %msg%n"/>
     <property name="LOG_PATTERN_SCHEDULE"    value="[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%-5level] %msg%n"/>
-    <property name="LOG_PATTERN_STATISTICS"  value="[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%-5level] %msg%n"/>
-<!--    <property name="LOG_PATTERN_CONSOLE"     value="[%d{HH:mm:ss.SSS}] %highlight([%5level]) %highlight(${PID:-}): %cyan(%msg) %n"/>-->
+    <property name="LOG_PATTERN_ASPECT"      value="[%d{yyyy-MM-dd HH:mm:ss.SSS}] [%-5level] %msg%n"/>
     <property name="LOG_PATTERN_CONSOLE"     value="[%d{HH:mm:ss.SSS}] [%5level] %msg %n"/>
 
     <springProfile name="!xxx">
@@ -41,25 +40,26 @@
         <appender-ref ref="FILE_ERROR"/>
     </root>
 
-    <logger name="${APP_CLASS_PATH}.udp" level="INFO" additivity="false">
-        <appender-ref ref="FILE_PACKET"/>
+    <logger name="${APP_CLASS_PATH}.service" level="INFO" additivity="false">
+        <appender-ref ref="CONSOLE"/>
+        <appender-ref ref="FILE_STATISTICS"/>
         <appender-ref ref="FILE_ERROR"/>
     </logger>
 
-    <logger name="${APP_CLASS_PATH}.udp" level="INFO" additivity="true">
-        <appender-ref ref="FILE_SESSION"/>
+    <logger name="${APP_CLASS_PATH}.scheduler" level="INFO" additivity="false">
+        <appender-ref ref="CONSOLE"/>
+        <appender-ref ref="FILE_SCHEDULE"/>
         <appender-ref ref="FILE_ERROR"/>
     </logger>
 
-    <logger name="${APP_CLASS_PATH}.service" level="INFO" additivity="false">
+    <logger name="${APP_CLASS_PATH}.aspect" level="INFO" additivity="false">
         <appender-ref ref="CONSOLE"/>
-        <appender-ref ref="FILE_STATISTICS"/>
+        <appender-ref ref="FILE_ASPECT"/>
         <appender-ref ref="FILE_ERROR"/>
     </logger>
 
-    <logger name="${APP_CLASS_PATH}.scheduler" level="INFO" additivity="false">
-        <appender-ref ref="CONSOLE"/>
-        <appender-ref ref="FILE_SCHEDULE"/>
+    <logger name="${APP_CLASS_PATH}.xnet" level="INFO" additivity="false">
+        <appender-ref ref="FILE_PACKET"/>
         <appender-ref ref="FILE_ERROR"/>
     </logger>