실제 로그 경로 찾기 (Feat. 리눅스, 파일 디스크립터)

배경

• 어느 날씨 좋은 날, 사수님께서 "톰캣로그는 어떻게 찾느냐?"라는 질문을 하셨다.
• 아래는 내가 찾은 방법과 사수님이 알려주신 방법을 정리한 것이다.

내가 찾은 방법

1. 우선 톰캣은 자바로 되어 있기 때문에 java 프로세스를 조회하고, 조회한 프로세스 중에서 tomcat 프로세스를 찾는다.

[root@ms ~]# ps -ef | grep java
root      1352     1  7 Sep08 ?        2-00:08:59 /opt/Tims/3rd/java/bin/java -Djava.util.logging.config.file=/opt/Tims/web/web/conf/logging.properties -Dsun.nio.cs.map=x-windows-iso2022jp/ISO-2022-JP,Windows-31J/Shift_JIS -Djava.net.preferIPv4Stack=true -server -Xms2048M -Xmx2048M -XX:PermSize=256m -XX:MaxPermSize=256M -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/app/tms7/log/catalina/web/20200908180326_heapdump_web.hprof -XX:+UsePerfData -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.endorsed.dirs= -classpath /opt/Tims/web/web/bin/tomcat-juli.jar:/opt/Tims/web/web/bin/bootstrap.jar -Dcatalina.base=/opt/Tims/web/web -Dcatalina.home=/opt/Tims/web/web -Djava.io.tmpdir=/opt/Tims/web/web/temp org.apache.catalina.startup.Bootstrap start

2. catalina 경로를 확인하고 실제 로그를 확인한다. > 근데 결과가 좀 이상하다?

[root@ms ~]# tail -f -n 100 /opt/Tims/web/web/logs/catalina.2020-10-05.log
          at org.apache.coyote.http11.InternalInputBuffer.parseRequestLine(InternalInputBuffer.java:213)
          at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1108)
          at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:654)
          at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:317)
          at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)
          at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)
          at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
          at java.lang.Thread.run(Thread.java:745)
     10월 05, 2020 10:33:48 오전 org.apache.coyote.http11.AbstractHttp11Processor process  
     정보: HTTP 요청 헤더를 파싱하는 중 오류 발생  
     비고: HTTP 요청 파싱 오류들이 더 발생하는 경우 DEBUG 레벨 로그로 기록될 것입니다.  
     java.lang.IllegalArgumentException: 요청 타겟에서 유효하지 않은 문자가 발견되었습니다. 유효한 문자들은 RFC 7230과 RFC 3986에 정의되어 있습니다.  
     at org.apache.coyote.http11.InternalInputBuffer.parseRequestLine(InternalInputBuffer.java:213)  
     at org.apache.coyote.http11.AbstractHttp11Processor.process(AbstractHttp11Processor.java:1108)  
     at org.apache.coyote.AbstractProtocol$AbstractConnectionHandler.process(AbstractProtocol.java:654)  
     at org.apache.tomcat.util.net.JIoEndpoint$SocketProcessor.run(JIoEndpoint.java:319)  
     at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1145)  
     at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:615)  
     at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)  
     at java.lang.Thread.run(Thread.java:745)

3. 결과가 이상한 것 같아, 위에 logging.properties 로그 설정파일에서 경로를 확인한다. => 결과는 catalina 로그를 본 것과 동일했다..

handlers = 1catalina.org.apache.juli.FileHandler, 2localhost.org.apache.juli.FileHandler, 3manager.org.apache.juli.FileHandler, 4host-manager.org.apache.juli.FileHandler, java.util.logging.ConsoleHandler

.handlers = 1catalina.org.apache.juli.FileHandler, java.util.logging.ConsoleHandler

1catalina.org.apache.juli.FileHandler.level = FINE
1catalina.org.apache.juli.FileHandler.directory = ${catalina.base}/logs
1catalina.org.apache.juli.FileHandler.prefix = catalina.
1catalina.org.apache.juli.FileHandler.encoding = UTF-8

2localhost.org.apache.juli.FileHandler.level = FINE  
2localhost.org.apache.juli.FileHandler.directory = ${catalina.base}/logs
2localhost.org.apache.juli.FileHandler.prefix = localhost.
2localhost.org.apache.juli.FileHandler.encoding = UTF-8

3manager.org.apache.juli.FileHandler.level = FINE  
3manager.org.apache.juli.FileHandler.directory = ${catalina.base}/logs
3manager.org.apache.juli.FileHandler.prefix = manager.
3manager.org.apache.juli.FileHandler.encoding = UTF-8

4host-manager.org.apache.juli.FileHandler.level = FINE
4host-manager.org.apache.juli.FileHandler.directory = ${catalina.base}/logs
4host-manager.org.apache.juli.FileHandler.prefix = host-manager.
4host-manager.org.apache.juli.FileHandler.encoding = UTF-8

java.util.logging.ConsoleHandler.level = FINE
java.util.logging.ConsoleHandler.formatter = java.util.logging.SimpleFormatter
java.util.logging.ConsoleHandler.encoding = UTF-8

사수님의 로그 찾는 방법

• 우선 리눅스의 모든 정보는 파일디스크립터로 관리된다.
  • 프로세스, 파일, 소켓 등등등 모든 것

1. 리눅스에서 관리하는 프로세스를 찾고, 그 프로세스의 파일 디스크립터를 찾는다.

• tomcat 프로세스 아이디 조회

[root@ms fd]# ps -ef | grep java
root      1352     1  7 Sep08 ?        2-00:08:59 /opt/Tims/3rd/java/bin/java -Djava.util.logging.config.file=/opt/Tims/web/web/conf/logging.properties -Dsun.nio.cs.map=x-windows-iso2022jp/ISO-2022-JP,Windows-31J/Shift_JIS -Djava.net.preferIPv4Stack=true -server -Xms2048M -Xmx2048M -XX:PermSize=256m -XX:MaxPermSize=256M -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/app/tms7/log/catalina/web/20200908180326_heapdump_web.hprof -XX:+UsePerfData -Djava.util.logging.manager=org.apache.juli.ClassLoaderLogManager -Djava.endorsed.dirs= -classpath /opt/Tims/web/web/bin/tomcat-juli.jar:/opt/Tims/web/web/bin/bootstrap.jar -Dcatalina.base=/opt/Tims/web/web -Dcatalina.home=/opt/Tims/web/web -Djava.io.tmpdir=/opt/Tims/web/web/temp org.apache.catalina.startup.Bootstrap start

• 해당 프로세스의 파일 디스크립터 조회

[root@ms fd]# ls -al /proc/1352/fd  
합계 0  
dr-x------ 2 root root 0 2020-09-19 05:08 .  
dr-xr-xr-x 8 root root 0 2020-09-11 05:12 ..  
lrwx------ 1 root root 64 2020-10-05 15:26 0 -> /dev/pts/1 (deleted)  
l-wx------ 1 root root 64 2020-10-05 15:26 1 -> pipe:[398586248]  
l-wx------ 1 root root 64 2020-10-05 15:26 10 -> /app/tms7/web/web/logs/manager.2020-09-08.log

=> 일반적으로 표준 출력에 로그 파일 경로가 있어야 하는데, pipe가 되어 있다.
( 0: 표준 입력, 1: 표준 출력, 2: 표준 에러 )

2. 파이프를 찾아가보자.
   => 아래와 같이 다른 1352 프로세스에서 표준 출력 및 에러 출력을 하면, 1353 프로세스에서 표준 입력을 받고 있다.
   이제 1353 프로세스만 찾으면 될 것 같다.

[root@ms fd]# lsof | grep 398586248  
java 1352 root 1w FIFO 0,8 0t0 398586248 pipe  
java 1352 root 2w FIFO 0,8 0t0 398586248 pipe  
cronolog 1353 root 0r FIFO 0,8 0t0 398586248 pipe

3. 1353 프로세스를 찾아 들어간다.
   => PIPE로 입력받아서, 사용자가 지정한 파일로 출력하고 있음을 알 수 있다.
   => 참고로 사용자가 지정하는 입출력 즉, 표준 입출력이 아닌 I/O행위의 파일 디스크립터는 3번 이후부터 순차적으로 생성된다.

[root@ms fd]# ls -al /proc/1353/fd  
합계 0  
dr-x------ 2 root root 0 2020-10-05 13:57 .  
dr-xr-xr-x 8 root root 0 2020-10-03 08:45 ..  
lr-x------ 1 root root 64 2020-10-05 15:26 0 -> pipe:[398586248]  
lrwx------ 1 root root 64 2020-10-05 15:26 1 -> /dev/pts/1 (deleted)  
lrwx------ 1 root root 64 2020-10-05 15:26 2 -> /dev/pts/1 (deleted)  
l-wx------ 1 root root 64 2020-10-05 15:26 3 -> /data3/log/catalina/web/20201005.log

4. 해당 로그 파일을 살펴보면, 실제 로그가 쌓이고 있음을 알 수 있었다.

결론

• 지금까지 리눅스위에서 작업을 했었다고 생각했었는데, 전혀 아니었다. (리눅스를 제대로 사용하지 못했었기 때문에)
• 알고 있는 지식이라도 활용하지 않으면, 모르는 것이다. (파일디스크립터를 알고 있었지만, 사용하지 않았기 때문에)
• 문제를 해결할 때, 핵심에서 부터 시작해야 한다.

느낀점

• 나에게는 충격도 정말 이런 충격이 없었다.
  "난 지금까지 무얼 했는가?"
  "내가 알고 있는 것은 무엇인가?"
  "알고 있는 것이 있기는 한가?"
• 진짜 앞으로 공부할 게 산더미구나.
• 처음부터 하나씩 하나씩 다시 시작해보자.