Tomcat 은 훌륭한 WAS 이다. 그대로 갖다 쓰면 되는 것을 이짓저짓 해가면서 에러를 발생시킨다. 오늘도 어김없이 뻘짓을 하다가 에러를 발생시킨다. Tomcat7 과 Tomcat8 을 동시에 올리는 과정에서 에러가 발생했다. 각각 그대로 썼다면 문제가 없었겠지만 멀티 인스턴스를 생성하는 과정에서 Tomcat7 기반에다가 Tomcat8 설정을 그대로 가져왔더니 에러가 발생했다. 왜 이런 짓을 했는지는 비밀이다.ㅋㅋ

 

28-Jun-2021 14:01:19.636 경고 [main] org.apache.catalina.startup.ClassLoaderFactory.validateFile Problem with directory [/app/tomcat7-jdk1.6/bin/"/app/instances/instance6/lib"], exists: [false], isDirectory: [false], canRead: [false]
28-Jun-2021 14:01:19.637 경고 [main] org.apache.catalina.startup.ClassLoaderFactory.validateFile Problem with directory [/app/tomcat7-jdk1.6/bin/"/app/instances/instance6/lib/*.jar"], exists: [false], isDirectory: [false], canRead: [false]
28-Jun-2021 14:01:19.637 경고 [main] org.apache.catalina.startup.ClassLoaderFactory.validateFile Problem with directory [/app/tomcat7-jdk1.6/bin/"/app/tomcat7-jdk1.6/lib"], exists: [false], isDirectory: [false], canRead: [false]
28-Jun-2021 14:01:19.638 경고 [main] org.apache.catalina.startup.ClassLoaderFactory.validateFile Problem with directory [/app/tomcat7-jdk1.6/bin/"/app/tomcat7-jdk1.6/lib/*.jar"], exists: [false], isDirectory: [false], canRead: [false]

 

음... 한글 로그가 참 눈에 거슬린다. 결론부터 얘기하자면 설정에 따옴표(") 가 붙은게 문제이다. tomcat8 에는 로더 간에 따옴표(")로 구분을 하였고, tomcat7 에는 따옴표가 없는데... 그 때문이다. 

 

(Tomcat8, conf/catalina.properties)
common.loader="${catalina.base}/lib","${catalina.base}/lib/*.jar","${catalina.home}/lib","${catalina.home}/lib/*.jar"

(Tomcat7, conf/catalina.properties)
common.loader=${catalina.base}/lib,${catalina.base}/lib/*.jar,${catalina.home}/lib,${catalina.home}/lib/*.jar

 

필요에 맞게 따옴표(") 를 넣거나 빼면 된다. 

 

기본 그대로 잘 쓰면 에러 안난다.ㅋ


WRITTEN BY
손가락귀신
정신 못차리면, 벌 받는다.

,

간만에 재미진 일.


간만에 사이트 운영팀에서 오류 문의가 속출했다. 등록이 안된다느니, 상세 페이지가 빈화면으로 나온다느니... 훗~ 걱정마라. 언제나 처럼 이 오빠가 해결해 줄테니.


우선 이 님들의 증상이 나에게도 동일한지 확인하였다. 특정 페이지들이 서버 500 에러도 있었지만 status 200 인데 빈화면이 나오는 기괴한 장면이 보여졌다. 동일한 소스의 개발 서버에는 정상적으로 작동하고 있었다. 실서버 로그를 확인해보니, 어제 아무개팀에서 인증서를 갱신했다.(내가 하던걸 왠일로...) 근데 로그를 뒤져보니 그 시간 이후로 오류가 속출했다. 잡았다, 요놈!! 공통적으로 주로 나온 오류들이다. 


INFO [main] org.apache.coyote.AbstractProtocol.destroy Destroying ProtocolHandler ["https-jsse-nio-8443"]

java.util.logging.ErrorManager: 4

java.io.FileNotFoundException: /usr/share/tomcat8/logs/catalina.2020-01-08.log (Permission denied)

        at java.io.FileOutputStream.open0(Native Method)

...


INFO [main] org.apache.catalina.core.StandardService.stopInternal Stopping service [Catalina]

[localhost-startStop-2] ERROR o.a.c.s.StandardManager - Exception unloading sessions to persistent storage

java.io.FileNotFoundException: /usr/share/tomcat8/work/Catalina/localhost/ROOT/SESSIONS.ser (Permission denied)

        at java.io.FileOutputStream.open0(Native Method)

...


SEVERE [https-jsse-nio-8443-exec-6] org.apache.catalina.core.StandardWrapperValve.invoke Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception

 org.springframework.web.multipart.MultipartException: Could not parse multipart servlet request; nested exception is java.io.IOException: org.apache.tomcat.util.http.fileupload.FileUploadBase$IOFileUploadException: Processing of multipart/form-data request failed. /var/cache/tomcat8/work/Catalina/localhost/ROOT/upload_46c524e4_8548_4273_9717_ff2e98ca4a2d_00000000.tmp (Permission denied)

        at org.springframework.web.multipart.support.StandardMultipartHttpServletRequest.parseRequest (StandardMultipartHttpServletRequest.java:112)

...


그리고 status 200 이지만 빈화면 나오면서 발생한 로그...


[https-jsse-nio-8443-exec-9] ERROR o.s.b.w.s.ErrorPageFilter - Cannot forward to error page for request [/manage/admin/9] as the response has already been committed. As a result, the response may have the wrong status code. If your application is running on WebSphere Application Server you may be able to resolve this problem by setting com.ibm.ws.webcontainer.invokeFlushAfterService to false


조금 당황스러웠다. 평소에 보던 오류도 아니고... 한가지 힌트는 Permission denied 하난데. 히스토리를 보니 인증서 갱신하고 몇번 톰캣 재부팅을 하는 과정에서 사용자 권한이 좀 꼬인것 같았다. 문제되는 파일들의 소유자가 모두 ROOT 로 실행되어 있던것이 문제. 후... 인증서 갱신하고 톰캣 재부팅만 하면 되는건데 뭐 때문에 ROOT 로 톰캣을 실행시켰을까 ㅡ.ㅡ 톰캣 재부팅으로도 문제는 해결되지 않았다. 이 파일들을 다 일일히 어떻게 찾아서 지우나 고민하던 중 빛과 같은 한 줄기 로그.


[localhost-startStop-1] ERROR o.a.j.EmbeddedServletOptions - The scratchDir you specified: [/usr/share/tomcat8/work/Catalina/localhost/ROOT] is unusable.



캐쉬 디렉토리 같은데 /usr/share/tomcat8/work/Catalina/localhost/ROOT 이 디렉토리를 삭제하니 문제가 해결됐다.

오예~


WRITTEN BY
손가락귀신
정신 못차리면, 벌 받는다.

,

tomcat 로그 catalina.out 에서 무수히 발견된 로그들.


30-Sep-2019 09:49:42.578 SEVERE [http-nio-8080-exec-32] org.apache.coyote.http11.Http11Processor.service Error processing request

        java.lang.NullPointerException


org.apache.coyote.http11.Http11Processor 는 http 요청을 처리한다. 위 로그는 server.xml 에 정의된 defaulthostname 이 null 이기 때문에 발생한 예외이다. server.xml 에는 아래와 같은 설정이 기본적으로 되어 있다.


<Engine name="Catalina" defaultHost="localhost">

    <Host name="localhost" appBase="webapps" unpackWARs="true" autoDeploy="true"></Host>


Hostname 을 localhost 그대로 사용할 경우엔 예외가 발생하지 않는다. Hostname 을 변경하고 서버가 직접 요청 받는 경우도 발생하지 않는다. Hostname 을 변경하도나서 로드밸런스 등으로 전달되는 경우 특히 발생하는 것 같다. 예외 발생 빈도는 심하지 않고 시점은 불규칙해서 알 수 없다.


저 예외를 없애려면 Catalina 안에 <Host name="localhost"></Host> 를 한줄 추가하면 해결된다.




WRITTEN BY
손가락귀신
정신 못차리면, 벌 받는다.

,

* catalina.out 로그


29-Sep-2019 15:12:51.096 INFO [http-nio-8080-exec-29] org.apache.coyote.http11.Http11Processor.service Error parsing HTTP request header

 Note: further occurrences of HTTP header parsing errors will be logged at DEBUG level.

        java.lang.IllegalArgumentException: Invalid character found in the request target. The valid characters are defined in RFC 7230 and RFC 3986

                at org.apache.coyote.http11.Http11InputBuffer.parseRequestLine(Http11InputBuffer.java:483)

                at org.apache.coyote.http11.Http11Processor.service(Http11Processor.java:684)

                at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:66)

                at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:808)

                at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1498)

                at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:49)

                at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)

                at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)

                at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)

                at java.lang.Thread.run(Thread.java:748)


Tomcat 8.0.39 버전부터 Query String 에 RFC 7230과 RFC 3986 문서에서 정의되지 않은 문자열을 포함할 경우(^`\|{}[] 같은 특수문자) 발생하는 400 오류(Bad Request) 이다. server.xml 에서 요청받는 Connector 태그에 relaxedQueryChars 속성을 추가하고 허용할 문자열을 정의하여 해결한다.


<Connector port="8080" protocol="HTTP/1.1" ... relaxedQueryChars="^`\|{}[]" />

<Connector port="8443" protocol="HTTP/1.1" ... relaxedQueryChars="^`\|{}[]" />




WRITTEN BY
손가락귀신
정신 못차리면, 벌 받는다.

,

s3 업로드시 발생하는 로그.


Sep 30 03:29:32 ip-172-50-10-72 tomcat8: 2019-09-30 12:29:32.717  WARN 27104 --- [io-8443-exec-65] c.amazonaws.services.s3.AmazonS3Client   : No content length specified for stream data.  Stream contents will be buffered in memory and could result in out of memory errors.


s3 업로드시 setContentLength 를 지정하지 않거나 IOUtils.toByteArray(inputStream) 사용시 inputStream 이 소진되어 발생하는 경고이며 다음과 같이 수정이 필요하다.


byte[] bytes = IOUtils.toByteArray(inputStream);
objectMetadata.setContentLength(bytes.length);
ByteArrayInputStream byteArrayInputStream = new ByteArrayInputStream(bytes);
 
PutObjectRequest putObjectRequest = new PutObjectRequest(bucket, key, byteArrayInputStream, objectMetadata);
client.putObject(putObjectRequest);
cs




WRITTEN BY
손가락귀신
정신 못차리면, 벌 받는다.

,