update logging thread to asynclogger

tsi-comm-server/build.gradle

@@ -68,6 +68,12 @@ dependencies {
 
 test {
     useJUnitPlatform()
+//    testLogging {
+//        events "started", "passed", "skipped", "failed"
+//        exceptionFormat "full"
+//        showStandardStreams = true // 표준 출력(System.out)과 표준 에러(System.err)를 보여줌
+//        showStackTraces = true
+//    }
 }
 
 jar {

tsi-comm-server/src/main/java/com/tsi/comm/server/config/SchedulingConfig.java

@@ -18,12 +18,15 @@ public class SchedulingConfig implements SchedulingConfigurer {
 
     private int poolSize = 0;
 
-    private final int SCHEDULE_THREAD_POOL_SIZE = 10;
+    private final int MIN_POOL_SIZE = 10;
+    private final int MAX_POOL_SIZE = 20; // 40코어라도 20개까지만 사용
 
     @PostConstruct
     private void init() {
-        if (this.poolSize < this.SCHEDULE_THREAD_POOL_SIZE) {
-            this.poolSize = this.SCHEDULE_THREAD_POOL_SIZE;
+        if (this.poolSize <= 0) {
+            int availableProcessors = Runtime.getRuntime().availableProcessors();
+            this.poolSize = Math.max(this.MIN_POOL_SIZE, availableProcessors);
+            this.poolSize = Math.min(this.poolSize, this.MAX_POOL_SIZE);
         }
         log.info("[SchedulingConfig] ------------");
         log.info("[SchedulingConfig] poolCore: {} EA.", this.poolSize);

tsi-comm-server/src/main/java/com/tsi/comm/server/config/ThreadPoolInitializer.java

@@ -4,9 +4,7 @@ import lombok.Data;
 import lombok.EqualsAndHashCode;
 import lombok.extern.slf4j.Slf4j;
 import org.jetbrains.annotations.NotNull;
-import org.springframework.boot.context.properties.ConfigurationProperties;
 import org.springframework.context.annotation.Bean;
-import org.springframework.context.annotation.Configuration;
 import org.springframework.scheduling.annotation.AsyncConfigurerSupport;
 import org.springframework.scheduling.concurrent.ThreadPoolTaskExecutor;
 
@@ -16,8 +14,9 @@ import java.util.concurrent.Executor;
 @EqualsAndHashCode(callSuper = true)
 @Slf4j
 @Data
-@Configuration
-@ConfigurationProperties(prefix = "application.thread-pool")
+// 사용하지 않음.
+//@Configuration
+//@ConfigurationProperties(prefix = "application.thread-pool")
 public class ThreadPoolInitializer extends AsyncConfigurerSupport {
 
     private int poolCore = 0;

tsi-comm-server/src/main/java/com/tsi/comm/server/process/packet/TsiCvimPacketWorker.java

@@ -210,10 +210,6 @@ public class TsiCvimPacketWorker extends AbstractTsiCvimWorker implements Runnab
                 return false;   // 네트워크 연결이 끊어진 경우
             }
 
-            if (-4 == result) {
-                return false; // 패킷 버퍼가 null 이거나 너무 짧은 경우
-            }
-
             if (cpuPacket.getBuf() != null) {
                 byte version = 0x00;
                 byte[] buf = cpuPacket.getBuf();

tsi-comm-server/src/main/java/com/tsi/comm/server/protocol/TsiCpuPacket.java

@@ -130,17 +130,17 @@ public class TsiCpuPacket extends AbstractTsiPacket {
         // 체크섬 계산하지 않음
     }
 
-    protected int checkPacket(TsiNodeVo obj, boolean checkCrc) {
+    protected int checkPacket(TsiNodeVo obj, boolean isCheckCrcError) {
 
         if (this.buf == null) {
             log.error("parsing: errno(-1), NodeId: {}, buf==null", this.nodeId);
-            return -1;
+            return -2;
         }
         // 0 단계. STX1, STX2 체크
         if (this.buf[INDEX_STX1] != STX1 || this.buf[INDEX_STX2] != STX2) {
             TsiCpuPacket.alarmAddManager.reportPacketError(this.nodeId, this.buf, "STX", (int)(this.buf[INDEX_STX1] & 0xFF), (int)(this.buf[INDEX_STX2] & 0xFF));
-            log.error("parsing: errno(-1), NodeId: {}, stx1: {}, stx2: {}", this.nodeId, this.buf[INDEX_STX1], this.buf[INDEX_STX2]);
-            return -1;
+            log.error("parsing: errno(-3), NodeId: {}, stx1: {}, stx2: {}", this.nodeId, this.buf[INDEX_STX1], this.buf[INDEX_STX2]);
+            return -3;
         }
 
         // 1 단계. 패킷 길이 체크
@@ -155,8 +155,16 @@ public class TsiCpuPacket extends AbstractTsiPacket {
         final int reqLength = SIZE_PACKET_DATA + (SIZE_STATUS_DATA * this.count);
         if (this.length < reqLength ) {
             TsiCpuPacket.alarmAddManager.reportPacketError(this.nodeId, this.buf, "LENGTH", reqLength, this.length);
-            log.error("parsing: errno(-2), NodeId: {}, reqLength: {}, recvLength: {}", this.nodeId, reqLength, this.length);
-            return -2;
+            log.error("parsing: errno(-4), NodeId: {}, reqLength: {}, recvLength: {}", this.nodeId, reqLength, this.length);
+            return -4;
+        }
+
+        final int reqPacketLength = reqLength + 2;  // stx1 + stx2
+        if (this.buf.length < reqPacketLength) {
+            TsiCpuPacket.alarmAddManager.reportPacketError(this.nodeId, this.buf, "PACKET_LENGTH", reqPacketLength, this.buf.length);
+            log.error("parsing: errno(-5), NodeId: {}, Packet reqLength: {}, recvLength: {}",
+                    this.nodeId, reqPacketLength, this.buf.length);
+            return -5;
         }
 
         // 2단계. 체크섬
@@ -164,34 +172,32 @@ public class TsiCpuPacket extends AbstractTsiPacket {
         final int calculatedCrc = CRC16Utils.CRC16_ccitt_cvim(this.buf, INDEX_LENGTH, this.length-2);  // 시작인덱스가 있으므로 전체길이로 계산
         if (receivedCrc != calculatedCrc) {
             TsiCpuPacket.alarmAddManager.reportCrcError(this.nodeId, this.buf, receivedCrc, calculatedCrc);
-            if (checkCrc || (obj != null && obj.isDump())) {
-                log.error("parsing: errno(-3), NodeId: {}, crc(recv/calc): {}/{}", this.nodeId, receivedCrc, calculatedCrc);
+            if (isCheckCrcError || (obj != null && obj.isDump())) {
+                log.error("parsing: errno(-9), NodeId: {}, crc(recv/calc): {}/{}", this.nodeId, receivedCrc, calculatedCrc);
             }
-            return -3;
+            return isCheckCrcError ? -9 : 0;   // CRC 체크하면 오류 리턴, 아니면 성공 리턴
         }
         return 0;
     }
 
-    public int parsing(TsiNodeVo obj, boolean isCheckPacket) {
+    public int parsing(TsiNodeVo obj, boolean isCheckCrcError) {
 
-        if (this.buf == null || this.buf.length < INDEX_STATUS_HDR+3) {
-            log.error("parsing: errno(-4), NodeId: {}, buf==null: {}, length: {}", this.nodeId, this.buf == null, this.buf == null ? 0 : this.buf.length);
-            return -4;
+        final int indexStatusCount = INDEX_STATUS_HDR + 3;  // 상태헤더의 3번째 바이트 = 10 + 3
+        if (this.buf == null || this.buf.length < indexStatusCount) {
+            log.error("parsing: errno(-1), NodeId: {}, buf==null: {}, length: {}", this.nodeId, this.buf == null, this.buf == null ? 0 : this.buf.length);
+            return -1;
         }
 
-        this.opCode = this.buf[INDEX_OPCODE];
-        this.dataVer = this.buf[INDEX_VERSION];
-        this.length = ByteUtils.getUnsignedShort(this.buf, INDEX_LENGTH);
-        this.count = (int)(this.buf[INDEX_STATUS_HDR+3] & 0x7F);
+        this.length = ByteUtils.getUnsignedShort(this.buf, INDEX_LENGTH);   // 2
+        this.opCode = this.buf[INDEX_OPCODE];                               // 4
+        this.dataVer = this.buf[INDEX_VERSION];                             // 5
+        this.count = (int)(this.buf[indexStatusCount] & 0x7F);              // 13
 
         obj.setSigCount(this.count);    // 신호현시 갯수 저장
 
-        int result = checkPacket(obj, isCheckPacket);
+        int result = checkPacket(obj, isCheckCrcError);
         if (0 != result) {
-            if (isCheckPacket) {
-                // 20250425: CRC 체크여부에 따라 바로 리턴(기본값은 체크여부가 true 임)
-                return result;
-            }
+            return result;
         }
 
         // CVIM 데이터 및 TEST 데이터가 생성됨

tsi-comm-server/src/main/java/com/tsi/comm/server/repository/TsiReportManager.java

@@ -34,13 +34,14 @@ public class TsiReportManager {
     private final TsiCvimDbmsProcess dbmsProcess;
     private final TsiCvimLoggingProcess loggingProcess;
     private final TsiCvimPacketProcess packetProcess;
+    final String head = "================================================================================================================";
 
     public void reportNodeSessions() {
         final String fileName = "report";
         MDC.put("filename", fileName);
 
         int nodeCount = this.nodeManager.getTsiNodeVoMap().size();
-        log.info("================================================================================================================");
+        log.info(this.head);
         log.info("Report Node Sessions: {} Nodes.", nodeCount);
 
         int registered = 0;
@@ -146,13 +147,13 @@ public class TsiReportManager {
         boolean isTail = false;
         int remainingCapacity = 0;
 
-        if (!isAlert) {
-            log.info("================================================================================================================");
+        if (isAlert) {
+            log.info(this.head);
             log.info("Worker Queue Information.");
         }
         List<AbstractTsiCvimWorker> processWorkerList = this.packetProcess.getWorkerList();
-        remainingCapacity = isAlert ? 100 : this.packetProcess.getQSize();
-        if (!isAlert) {
+        remainingCapacity = isAlert ? this.packetProcess.getQSize() : 100;
+        if (isAlert) {
             log.info("-----  Packet Worker: {} EA, QSize: {} EA.", processWorkerList.size(), this.packetProcess.getQSize());
         }
         List<TsiCvimPacketWorker> packetWorkers = processWorkerList.stream()
@@ -170,8 +171,8 @@ public class TsiReportManager {
         }
 
         List<AbstractTsiCvimWorker> dbmsWorkerList = this.dbmsProcess.getWorkerList();
-        remainingCapacity = isAlert ? 100 : this.dbmsProcess.getQSize();
-        if (!isAlert) {
+        remainingCapacity = isAlert ? this.dbmsProcess.getQSize() : 100;
+        if (isAlert) {
             log.info("-----    Dbms Worker: {} EA, QSize: {} EA.", dbmsWorkerList.size(), this.dbmsProcess.getQSize());
         }
         List<TsiCvimDbmsWorker> dbmsWorkers = dbmsWorkerList.stream()
@@ -189,8 +190,8 @@ public class TsiReportManager {
         }
         if (this.loggingProcess.isEnabled()) {
             List<AbstractTsiCvimWorker> loggingWorkerList = this.loggingProcess.getWorkerList();
-            remainingCapacity = isAlert ? 100 : this.loggingProcess.getQSize();
-            if (!isAlert) {
+            remainingCapacity = isAlert ? this.loggingProcess.getQSize() : 100;
+            if (isAlert) {
                 log.info("----- Logging Worker: {} EA, QSize: {} EA.", loggingWorkerList.size(), this.loggingProcess.getQSize());
             }
             List<TsiCvimLoggingWorker> loggingWorkers = loggingWorkerList.stream()
@@ -208,13 +209,13 @@ public class TsiReportManager {
             }
         }
         else {
-            if (!isAlert) {
+            if (isAlert) {
                 log.info(" Logging Worker is disabled (useLoggingThread=false).");
             }
         }
 
         if (isTail) {
-            log.info("================================================================================================================");
+            log.info(this.head);
         }
         MDC.clear();
     }

tsi-comm-server/src/main/java/com/tsi/comm/server/repository/TsiTpmsManager.java

@@ -24,13 +24,13 @@ public class TsiTpmsManager {
 
     // 패킷 수
     private final Counter readTPS = new Counter();    // read transaction per seconds
-    private final Counter readTPM = new Counter();    // read transaction per minute
-    private final Counter readTPD = new Counter();    // read transaction per day
+//    private final Counter readTPM = new Counter();    // read transaction per minute
+//    private final Counter readTPD = new Counter();    // read transaction per day
 
     // 패킷 바이트수
     private final Counter readBPS = new Counter();    // read bytes per seconds
-    private final Counter readBPM = new Counter();    // read bytes per minute
-    private final Counter readBPD = new Counter();    // read bytes per day
+//    private final Counter readBPM = new Counter();    // read bytes per minute
+//    private final Counter readBPD = new Counter();    // read bytes per day
 
     @Getter
     private final KafkaTransVo kafkaTransVo = new KafkaTransVo(AbstractDbmsVo.DBMS_KAFKA_TRANS_HS);
@@ -46,11 +46,11 @@ public class TsiTpmsManager {
         this.readTPS.increment();
         this.readBPS.add(packet.getBuf().length);
 
-        this.readTPM.increment();
-        this.readBPM.add(packet.getBuf().length);
-
-        this.readTPD.increment();
-        this.readBPD.add(packet.getBuf().length);
+//        this.readTPM.increment();
+//        this.readBPM.add(packet.getBuf().length);
+//
+//        this.readTPD.increment();
+//        this.readBPD.add(packet.getBuf().length);
     }
 
     public void resetSecond(int serverId, String hostName) {
@@ -69,17 +69,19 @@ public class TsiTpmsManager {
                 String.format("%,d", trans),
                 Converter.getSize(bytes), Thread.currentThread().getName());*/
     }
+
     public void resetMinute() {
-        long trans = this.readTPM.reset();  // read transaction per minute
-        long bytes = this.readBPM.reset();  // read bytes per minute
+//        long trans = this.readTPM.reset();  // read transaction per minute
+//        long bytes = this.readBPM.reset();  // read bytes per minute
         /*log.info("Minute Statistics: {} sessions, {} TRX, {}. {}",
                 TsiSessionManager.getInstance().get(),
                 String.format("%,d", trans),
                 Converter.getSize(bytes), Thread.currentThread().getName());*/
     }
+
     public void resetDay() {
-        long trans = this.readTPD.reset();  // read transaction per day
-        long bytes = this.readBPD.reset();  // read bytes per day
+//        long trans = this.readTPD.reset();  // read transaction per day
+//        long bytes = this.readBPD.reset();  // read bytes per day
         /*log.info("   Day Statistics: {} sessions, {} TRX, {}. {}",
                 TsiSessionManager.getInstance().get(),
                 String.format("%,d", trans),

tsi-comm-server/src/main/java/com/tsi/comm/server/scheduler/ApplicationScheduler.java

@@ -4,17 +4,15 @@ import com.tsi.comm.server.config.TraceConfig;
 import com.tsi.comm.server.config.TsiCvimServerConfig;
 import com.tsi.comm.server.kafka.KafkaConsumerService;
 import com.tsi.comm.server.kafka.KafkaProducerService;
-import com.tsi.comm.server.service.TsiCommServerService;
 import com.tsi.comm.server.repository.TsiAlarmManager;
 import com.tsi.comm.server.repository.TsiReportManager;
 import com.tsi.comm.server.repository.TsiTpmsManager;
-import com.tsi.comm.server.vo.TsiAlarmConfigVo;
+import com.tsi.comm.server.service.TsiCommServerService;
 import com.tsi.comm.server.xnet.NetUtils;
 import com.tsi.common.utils.Elapsed;
 import com.tsi.common.utils.TimeUtils;
 import lombok.RequiredArgsConstructor;
 import lombok.extern.slf4j.Slf4j;
-import org.springframework.scheduling.annotation.Async;
 import org.springframework.scheduling.annotation.EnableScheduling;
 import org.springframework.scheduling.annotation.Scheduled;
 import org.springframework.stereotype.Component;
@@ -43,7 +41,7 @@ public class ApplicationScheduler {
         this.hostName = NetUtils.getHostName();
     }
 
-    @Scheduled(cron = "0/5 * * * * *")  //
+    @Scheduled(cron = "0/5 * * * * *")
     public void staticsForPacketSecond() {
         if (!this.config.isStartup()) {
             return;
@@ -53,7 +51,7 @@ public class ApplicationScheduler {
 //        log.info("{}", String.format("%25s: %s", "staticsForPacketSecond", TimeUtils.elapsedTimeStr(elapsed.nanoSeconds())));
     }
 
-    @Scheduled(cron = "0/5 * * * * *")  //
+    @Scheduled(cron = "0/5 * * * * *")
     public void checkKafkaServerAlive() {
         if (!this.config.isStartup()) {
             return;
@@ -66,6 +64,30 @@ public class ApplicationScheduler {
         }
     }
 
+//    @Scheduled(cron = "0 * * * * *")  // 1분 주기 작업 실행
+//    public void staticsForPacketMinute() {
+//        if (!this.config.isStartup()) {
+//            return;
+//        }
+//        Elapsed elapsed = new Elapsed();
+//        this.tpmsManager.resetMinute();
+//        if (elapsed.milliSeconds() > 500) {
+//            log.info("{}", String.format("%25s: %s", "staticsForPacketMinute", TimeUtils.elapsedTimeStr(elapsed.nanoSeconds())));
+//        }
+//    }
+
+//    @Scheduled(cron = "0 0 0 * * *")  // 1일 주기 작업 실행
+//    public void staticsForPacketDay() {
+//        if (!this.config.isStartup()) {
+//            return;
+//        }
+//        Elapsed elapsed = new Elapsed();
+//        this.tpmsManager.resetDay();
+//        if (elapsed.milliSeconds() > 500) {
+//            log.info("{}", String.format("%25s: %s", "staticsForPacketDay", TimeUtils.elapsedTimeStr(elapsed.nanoSeconds())));
+//        }
+//    }
+
 //    @Scheduled(cron = "0/5 * * * * *")  //
 //    public void checkSessionTimeout() {
 //        if (!this.config.isStartup()) {
@@ -88,48 +110,18 @@ public class ApplicationScheduler {
 ////        log.info("{}", String.format("%25s: %s", "checkSessionTimeout", TimeUtils.elapsedTimeStr(elapsed.nanoSeconds())));
 //    }
 
-    @Scheduled(cron = "0/30 * * * * *")  // 30초 주기 작업 실행
-    public void reportNodeSessionAlive() {
-        if (!this.config.isStartup()) {
-            return;
-        }
-        if (!this.trace.isSessionReport()) {
-            return; // 세션 정보 보고 안함.
-        }
-        Elapsed elapsed = new Elapsed();
-        this.reportManager.reportNodeSessions();
-//        TsiSessionManager.getInstance().reportChannelSessions();
-//        log.info("{}", String.format("%25s: %s", "reportNodeSessionAlive", TimeUtils.elapsedTimeStr(elapsed.nanoSeconds())));
-    }
-
-    @Scheduled(cron = "5/35 * * * * *")  //
-    public void reportQueueInformation() {
-        if (!this.config.isStartup()) {
-            return;
-        }
-        if (this.trace.isQueueReport()) {
-            Elapsed elapsed = new Elapsed();
-            this.reportManager.reportQueueInfo(false);
-//            log.info("{}", String.format("%25s: %s", "reportQueueInformation", TimeUtils.elapsedTimeStr(elapsed.nanoSeconds())));
-        }
-        else {
-            this.reportManager.reportQueueInfo(true);
-        }
-    }
-
-    @Scheduled(cron = "0 * * * * *")  // 1분 주기 작업 실행
-    public void staticsForPacketMinute() {
+    @Scheduled(cron = "0/30 * * * * *")
+    public void reportSystem() {
         if (!this.config.isStartup()) {
             return;
         }
-        Elapsed elapsed = new Elapsed();
-        this.tpmsManager.resetMinute();
-        if (elapsed.milliSeconds() > 500) {
-            log.info("{}", String.format("%25s: %s", "staticsForPacketMinute", TimeUtils.elapsedTimeStr(elapsed.nanoSeconds())));
+        if (this.trace.isSessionReport()) {
+            this.reportManager.reportNodeSessions();
         }
+        this.reportManager.reportQueueInfo(this.trace.isQueueReport());
     }
 
-    @Scheduled(cron = "10 * * * * *")  //
+    @Scheduled(cron = "10 * * * * *")
     public void loadTraceInfo() {
         if (!this.config.isStartup()) {
             return;
@@ -141,19 +133,7 @@ public class ApplicationScheduler {
         }
     }
 
-    @Scheduled(cron = "0 0 0 * * *")  // 1일 주기 작업 실행
-    public void staticsForPacketDay() {
-        if (!this.config.isStartup()) {
-            return;
-        }
-        Elapsed elapsed = new Elapsed();
-        this.tpmsManager.resetDay();
-        if (elapsed.milliSeconds() > 500) {
-            log.info("{}", String.format("%25s: %s", "staticsForPacketDay", TimeUtils.elapsedTimeStr(elapsed.nanoSeconds())));
-        }
-    }
-
-    @Scheduled(cron = "0 0/5 * * * *")  //
+    @Scheduled(cron = "0 0/5 * * * *")
     public void loadBaseDatabase() {
         if (!this.config.isStartup()) {
             return;

tsi-comm-server/src/main/java/com/tsi/comm/server/xnet/ServerBootstrapFactory.java

@@ -1,6 +1,7 @@
 package com.tsi.comm.server.xnet;
 
 import io.netty.bootstrap.ServerBootstrap;
+import io.netty.buffer.PooledByteBufAllocator;
 import io.netty.channel.*;
 import lombok.extern.slf4j.Slf4j;
 
@@ -25,16 +26,35 @@ public class ServerBootstrapFactory {
         serverBootstrap.channel(NettyUtils.getServerSocketChannel());
         serverBootstrap.group(acceptGroups, workerGroups);
 
-        serverBootstrap.option(ChannelOption.AUTO_READ, true);
+        // --- 서버 소켓 옵션 (클라이언트 연결을 수락하는 소켓) ---
         serverBootstrap.option(ChannelOption.SO_BACKLOG, config.getBacklog());
         serverBootstrap.option(ChannelOption.SO_RCVBUF, config.getRcvBuf());
         serverBootstrap.option(ChannelOption.SO_REUSEADDR, true);
-        serverBootstrap.option(ChannelOption.CONNECT_TIMEOUT_MILLIS, config.getConnectTimeoutSeconds()*1000);
+//        serverBootstrap.option(ChannelOption.AUTO_READ, true);
 
-        serverBootstrap.childOption(ChannelOption.SO_LINGER, 0);           // 4way-handshake 비활성
-        serverBootstrap.childOption(ChannelOption.SO_KEEPALIVE, false);    // KEEPALIVE 비활성(활성: true)
+        // [추가 제안 1] Pooled Allocator 사용으로 GC 부담 감소
+        serverBootstrap.option(ChannelOption.ALLOCATOR, PooledByteBufAllocator.DEFAULT);
+
+        // --- 자식 소켓 옵션 (실제 데이터 통신이 일어나는 소켓) ---
         serverBootstrap.childOption(ChannelOption.SO_REUSEADDR, true);     // 소켓 재사용
         serverBootstrap.childOption(ChannelOption.TCP_NODELAY, true);      // Nagle 알고리즘 비활성화
+
+        // SO_KEEPALIVE는 보통 true로 설정하여 비정상적으로 끊어진 연결을 감지하는 용도
+        serverBootstrap.childOption(ChannelOption.SO_KEEPALIVE, false);    // KEEPALIVE 비활성(활성: true)
+
+        // SO_LINGER는 0으로 설정 시 close() 호출 시 즉시 연결을 끊습니다. (TIME_WAIT 상태를 건너뜀)
+        // 대량 연결 환경에서는 유용할 수 있으나, 데이터 유실 가능성이 있으므로 주의
+        serverBootstrap.childOption(ChannelOption.SO_LINGER, 0);           // 4way-handshake 비활성
+
+        // [추가 제안 2] Pooled Allocator 사용 (자식 채널에도 적용)
+        serverBootstrap.childOption(ChannelOption.ALLOCATOR, PooledByteBufAllocator.DEFAULT);
+
+        // 쓰기 큐에 512KB 이상 쌓이면 채널을 non-writable로 만들고, 1MB를 초과하면 안 됨.
+        // 무선신호는 데이터 전송을 하지 않기 때문에 사용하지 않음.
+//        serverBootstrap.childOption(ChannelOption.WRITE_BUFFER_WATER_MARK, new WriteBufferWaterMark(512 * 1024, 1024 * 1024));
+
+//        serverBootstrap.childOption(ChannelOption.AUTO_READ, true); // default: true
+
         serverBootstrap.childHandler((ChannelHandler)channelInitializer);
 
         return serverBootstrap;

tsi-comm-server/src/main/resources/logback-spring.xml

@@ -34,6 +34,7 @@
     <property name="LOG_PATTERN_RAW"         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"/>
 
+    <!-- ========================= CONSOLE ======================================================================= -->
     <appender name="CONSOLE" class="ch.qos.logback.core.ConsoleAppender">
         <withJansi>true</withJansi>
         <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
@@ -42,6 +43,7 @@
         </encoder>
     </appender>
 
+    <!-- ========================= FILE_ERROR ======================================================================= -->
     <appender name="FILE_ERROR" class="ch.qos.logback.core.rolling.RollingFileAppender">
         <filter class="ch.qos.logback.classic.filter.LevelFilter">
             <level>error</level>
@@ -59,7 +61,15 @@
             <maxHistory>${MAX_HISTORY}</maxHistory>
         </rollingPolicy>
     </appender>
+    <appender name="ASYNC_ERROR" class="ch.qos.logback.classic.AsyncAppender">
+        <queueSize>1000</queueSize>
+        <discardingThreshold>5</discardingThreshold>
+        <neverBlock>true</neverBlock>
+        <includeCallerData>false</includeCallerData>
+        <appender-ref ref="FILE_ERROR" />
+    </appender>
 
+    <!-- ========================= FILE_LOG ======================================================================= -->
     <appender name="FILE_LOG" class="ch.qos.logback.core.rolling.RollingFileAppender">
         <file>${LOG_PATH}${LOG_FILE_NAME}</file>
         <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
@@ -72,13 +82,23 @@
             <maxHistory>${MAX_HISTORY}</maxHistory>
         </rollingPolicy>
     </appender>
+    <appender name="ASYNC_LOG" class="ch.qos.logback.classic.AsyncAppender">
+        <queueSize>5000</queueSize>
+        <discardingThreshold>5</discardingThreshold>
+        <neverBlock>true</neverBlock>
+        <includeCallerData>false</includeCallerData>
+        <appender-ref ref="FILE_LOG" />
+    </appender>
 
+    <!-- ========================= FILE_PROCESS ======================================================================= -->
     <appender name="FILE_PROCESS" class="ch.qos.logback.classic.sift.SiftingAppender">
         <discriminator>
             <key>id</key>
             <defaultValue>${LOG_FILE_NAME_PROCESS}</defaultValue>
         </discriminator>
         <sift>
+            <!-- 5분 동안 사용되지 않은 Appender는 자동으로 닫힘 -->
+            <timeout>300000</timeout> <!-- 5분 = 300000 밀리초 -->
             <appender name="FILE-${id}" class="ch.qos.logback.core.rolling.RollingFileAppender">
                 <file>${LOG_PATH}process/${id}.log</file>
                 <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
@@ -131,12 +151,14 @@
         <appender-ref ref="FILE_ERROR"/>
     </logger>
 
+    <!-- ========================= INFO ======================================================================= -->
     <root level="INFO">
 <!--        <appender-ref ref="CONSOLE"/>-->
         <appender-ref ref="FILE_LOG"/>
         <appender-ref ref="FILE_ERROR"/>
     </root>
 
+    <!-- ========================= FILE_CONFIG ======================================================================= -->
     <appender name="FILE_CONFIG" class="ch.qos.logback.core.rolling.RollingFileAppender">
         <file>${LOG_PATH}${LOG_FILE_NAME_CONFIG}</file>
         <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
@@ -149,6 +171,13 @@
             <maxHistory>${MAX_HISTORY}</maxHistory>
         </rollingPolicy>
     </appender>
+<!--    <appender name="ASYNC_CONFIG" class="ch.qos.logback.classic.AsyncAppender">-->
+<!--        <queueSize>100</queueSize>-->
+<!--        <discardingThreshold>5</discardingThreshold>-->
+<!--        <neverBlock>true</neverBlock>-->
+<!--        <includeCallerData>false</includeCallerData>-->
+<!--        <appender-ref ref="FILE_CONFIG" />-->
+<!--    </appender>-->
 
     <logger name="com.tsi.comm.server.config" level="INFO" additivity="true">
         <appender-ref ref="CONSOLE"/>
@@ -161,6 +190,7 @@
         <appender-ref ref="FILE_ERROR"/>
     </logger>
 
+    <!-- ========================= FILE_DBMS ======================================================================= -->
     <appender name="FILE_DBMS" class="ch.qos.logback.core.rolling.RollingFileAppender">
         <file>${LOG_PATH}${LOG_FILE_NAME_DBMS}</file>
         <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
@@ -173,11 +203,20 @@
             <maxHistory>${MAX_HISTORY}</maxHistory>
         </rollingPolicy>
     </appender>
+    <appender name="ASYNC_DBMS" class="ch.qos.logback.classic.AsyncAppender">
+        <queueSize>3000</queueSize>
+        <discardingThreshold>5</discardingThreshold>
+        <neverBlock>true</neverBlock>
+        <includeCallerData>false</includeCallerData>
+        <appender-ref ref="FILE_DBMS" />
+    </appender>
+
     <logger name="com.tsi.comm.server.process.dbms" level="INFO" additivity="false">
         <appender-ref ref="FILE_DBMS"/>
         <appender-ref ref="FILE_ERROR"/>
     </logger>
 
+    <!-- ========================= FILE_SCHEDULE ======================================================================= -->
     <appender name="FILE_KAFKA" class="ch.qos.logback.core.rolling.RollingFileAppender">
         <file>${LOG_PATH}${LOG_FILE_NAME_KAFKA}</file>
         <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
@@ -190,11 +229,20 @@
             <maxHistory>${MAX_HISTORY}</maxHistory>
         </rollingPolicy>
     </appender>
+    <appender name="ASYNC_KAFKA" class="ch.qos.logback.classic.AsyncAppender">
+        <queueSize>10000</queueSize>
+        <discardingThreshold>5</discardingThreshold>
+        <neverBlock>true</neverBlock>
+        <includeCallerData>false</includeCallerData>
+        <appender-ref ref="FILE_KAFKA" />
+    </appender>
+
     <logger name="com.tsi.comm.server.kafka" level="INFO" additivity="false">
         <appender-ref ref="FILE_KAFKA"/>
         <appender-ref ref="FILE_ERROR"/>
     </logger>
 
+    <!-- ========================= FILE_SCHEDULE ======================================================================= -->
     <appender name="FILE_SESSION" class="ch.qos.logback.core.rolling.RollingFileAppender">
         <file>${LOG_PATH}${LOG_FILE_NAME_SESSION}</file>
         <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
@@ -207,12 +255,20 @@
             <maxHistory>${MAX_HISTORY}</maxHistory>
         </rollingPolicy>
     </appender>
+    <appender name="ASYNC_SESSION" class="ch.qos.logback.classic.AsyncAppender">
+        <queueSize>4000</queueSize>
+        <discardingThreshold>5</discardingThreshold>
+        <neverBlock>true</neverBlock>
+        <includeCallerData>false</includeCallerData>
+        <appender-ref ref="FILE_SESSION" />
+    </appender>
 
     <logger name="com.tsi.comm.server.tcp" level="INFO" additivity="false">
         <appender-ref ref="FILE_SESSION"/>
         <appender-ref ref="FILE_ERROR"/>
     </logger>
 
+    <!-- ========================= FILE_SCHEDULE ======================================================================= -->
     <appender name="FILE_REPORT" class="ch.qos.logback.classic.sift.SiftingAppender">
         <discriminator>
             <key>filename</key>
@@ -234,12 +290,20 @@
             </appender>
         </sift>
     </appender>
+    <appender name="ASYNC_REPORT" class="ch.qos.logback.classic.AsyncAppender">
+        <queueSize>1000</queueSize>
+        <discardingThreshold>5</discardingThreshold>
+        <neverBlock>true</neverBlock>
+        <includeCallerData>false</includeCallerData>
+        <appender-ref ref="FILE_REPORT" />
+    </appender>
 
     <logger name="com.tsi.comm.server.repository" level="INFO" additivity="false">
         <appender-ref ref="FILE_REPORT"/>
         <appender-ref ref="FILE_ERROR"/>
     </logger>
 
+<!-- ========================= FILE_SCHEDULE ======================================================================= -->
     <appender name="FILE_SCHEDULE" class="ch.qos.logback.core.rolling.RollingFileAppender">
         <file>${LOG_PATH}${LOG_FILE_NAME_SCHEDULE}</file>
         <encoder class="ch.qos.logback.classic.encoder.PatternLayoutEncoder">
@@ -252,6 +316,13 @@
             <maxHistory>${MAX_HISTORY}</maxHistory>
         </rollingPolicy>
     </appender>
+    <appender name="ASYNC_SCHEDULE" class="ch.qos.logback.classic.AsyncAppender">
+        <queueSize>1000</queueSize>
+        <discardingThreshold>5</discardingThreshold>
+        <neverBlock>true</neverBlock>
+        <includeCallerData>false</includeCallerData>
+        <appender-ref ref="FILE_SCHEDULE" />
+    </appender>
 
     <logger name="com.tsi.comm.server.scheduler" level="INFO" additivity="false">
         <appender-ref ref="FILE_SCHEDULE"/>

tsi-comm-server/src/test/java/com/tsi/comm/server/TsiCommServerApplicationTests.java

@@ -1,22 +1,44 @@
 package com.tsi.comm.server;
 
+import ch.qos.logback.classic.Logger;
+import ch.qos.logback.classic.spi.ILoggingEvent;
+import ch.qos.logback.core.Appender;
+import com.tsi.comm.server.kafka.KafkaConsumerService;
+import com.tsi.comm.server.kafka.KafkaProducerService;
+import com.tsi.comm.server.process.dbms.TsiCvimDbmsProcess;
 import com.tsi.comm.server.protocol.TsiCvibProtocolSpec;
+import com.tsi.comm.server.tcp.TsiCvimServer;
 import com.tsi.common.utils.ByteUtils;
 import com.tsi.common.utils.CRC16Utils;
 import com.tsi.common.utils.HexString;
 import lombok.extern.slf4j.Slf4j;
 import org.junit.jupiter.api.Test;
+import org.slf4j.LoggerFactory;
+import org.slf4j.MDC;
+import org.springframework.boot.test.context.SpringBootTest;
+import org.springframework.boot.test.mock.mockito.MockBean;
+import org.springframework.test.context.ActiveProfiles;
 
 import java.net.InetAddress;
 import java.net.UnknownHostException;
-import java.util.concurrent.Executors;
-import java.util.concurrent.ThreadFactory;
-import java.util.concurrent.ThreadPoolExecutor;
-import java.util.concurrent.TimeUnit;
+import java.util.concurrent.*;
 
+import static org.junit.jupiter.api.Assertions.assertTrue;
 @Slf4j
-//@SpringBootTest
+@SpringBootTest(classes = TsiCommServerApplication.class)
+@ActiveProfiles("dev")
 public class TsiCommServerApplicationTests {
+    @MockBean
+    private TsiCvimServer tsiCvimServer;
+
+    @MockBean
+    private KafkaConsumerService kafkaConsumerService;
+
+    @MockBean
+    private KafkaProducerService kafkaProducerService;
+
+    @MockBean
+    private TsiCvimDbmsProcess tsiCvimDbmsProcess;
 
     //@Test
     void contextLoads() {
@@ -131,17 +153,84 @@ public class TsiCommServerApplicationTests {
         long nodeId = 110000001;
         String strHex = "7E7E004E1301068E77810002310C60F1375E10CB280B0A20CB321F0A30CB320D0A10CA03011420CA32011430CA322B1410C9280B1E20C9321F1E30C9320D1E10C903012820C928012830C9282B28FD89";
         byte[] packet = ByteUtils.hexToByteArray(strHex);
-        log.error("{}", HexString.fromBytes(packet));
+        log.info("{}", HexString.fromBytes(packet));
         int dataLength = ByteUtils.getUnsignedShort(packet, TsiCvibProtocolSpec.INDEX_LENGTH);
-        log.error("dataLength: {}, packetLength: {}", dataLength, packet.length);
+        log.info("dataLength: {}, packetLength: {}", dataLength, packet.length);
         int recvCheckSum = ByteUtils.getUnsignedShort(packet, packet.length-2);
         int calcCheckSum = CRC16Utils.CRC16_ccitt_cvim(packet, 2, dataLength-2);
         if (recvCheckSum != calcCheckSum) {
-            log.info("Node: {}, Check Sum Error: {},{}, recv: {}, calc: {}", nodeId, 0xFD89, 0x89FD, recvCheckSum, calcCheckSum);
+            log.error("Node: {}, Check Sum Error: {},{}, recv: {}, calc: {}", nodeId, 0xFD89, 0x89FD, recvCheckSum, calcCheckSum);
         }
         else {
             log.info("Node: {}, Check Sum OK: recv: {}, calc: {}", nodeId, recvCheckSum, calcCheckSum);
         }
     }
 
+    @Test
+    public void testAsyncLoggingPerformance() throws InterruptedException {
+        final String TARGET_LOGGER_NAME = "com.tsi.comm.server.process.packet";
+        Logger logger = (Logger) LoggerFactory.getLogger(TARGET_LOGGER_NAME);
+
+        // System.out.println("Main thread waiting for latch...");
+        log.info("Main thread waiting for latch...");
+
+        // AsyncAppender가 잘 연결되었는지 확인 (선택 사항)
+         Appender<ILoggingEvent> asyncAppender = logger.getAppender("ASYNC_PROCESS");
+//         assertNotNull(asyncAppender, "ASYNC_PROCESS appender should be attached");
+
+        int threadCount = 10;
+        int logsPerThread = 1000;
+        ExecutorService executor = Executors.newFixedThreadPool(threadCount);
+        CountDownLatch latch = new CountDownLatch(threadCount);
+
+        long startTime = System.nanoTime();
+
+        for (int i = 0; i < threadCount; i++) {
+            final int threadId = i;
+            executor.submit(() -> {
+                try {
+                    System.out.println("Thread " + threadId + " started."); // [추가] 시작 로그
+                    MDC.put("id", String.valueOf(threadId));
+
+                    for (int j = 0; j < logsPerThread; j++) {
+                        logger.info("Performance Test Log Message - Thread: {}, Count: {}", threadId, j);
+                        // [선택] 너무 빠르면 100건마다 로그 찍어보기
+                        // if (j % 100 == 0) System.out.println("Thread " + threadId + " processed " + j);
+                    }
+                    System.out.println("Thread " + threadId + " finished."); // [추가] 종료 로그
+                } catch (Exception e) {
+                    e.printStackTrace();
+                } finally {
+                    MDC.clear();
+                    latch.countDown();
+                    System.out.println("Thread " + threadId + " latch counted down. Count: " + latch.getCount()); // [추가] 래치 로그
+                }
+            });
+        }
+
+        System.out.println("Main thread waiting for latch..."); // [추가]
+        boolean completed = latch.await(20, TimeUnit.SECONDS); // [수정] 타임아웃 20초로 늘림
+        System.out.println("Latch await finished. Completed: " + completed); // [추가]
+
+        long endTime = System.nanoTime();
+        long durationMillis = TimeUnit.NANOSECONDS.toMillis(endTime - startTime);
+
+        assertTrue(completed, "All logging threads should complete within timeout");
+
+        System.out.println("==================================================");
+        System.out.println("Total Logs Generated: " + (threadCount * logsPerThread));
+        System.out.println("Total Time Taken (Main Threads): " + durationMillis + " ms");
+        System.out.println("Throughput: " + ((threadCount * logsPerThread) * 1000 / durationMillis) + " logs/sec");
+        System.out.println("==================================================");
+
+        System.out.println("Waiting for AsyncAppender to drain the queue...");
+//        Thread.sleep(3000);
+
+//        System.out.println("Stopping LoggerContext to flush all async logs to disk...");
+//        LoggerContext loggerContext = (LoggerContext) LoggerFactory.getILoggerFactory();
+//        loggerContext.stop();
+//        System.out.println("LoggerContext stopped.");
+
+//        System.exit(0);
+    }
 }

tsi-common/build.gradle

@@ -45,6 +45,7 @@ bootJar {
 test {
     useJUnitPlatform()
 }
+
 publishing {
     publications {
         mavenJava(MavenPublication) {
@@ -54,7 +55,7 @@ publishing {
     repositories {
         maven {
             name = "customLocalRepo"
-            println "its-cluster library install mvn repository..."
+            println "tsi-common library install mvn repository..."
             def repoPath = org.gradle.internal.os.OperatingSystem.current().isWindows() ?
                     "C:/java/repository" :
                     "/Users/openvalue/Projects/java/repository"