Jenkins

위키백과에서 발췌한 내용에 따른다.
젠킨스(Jenkins)는 소프트웨어 개발 시 지속적 통합(continuous integration) 서비스를 제공하는 툴이다. 다수의 개발자들이 하나의 프로그램을 개발할 때 버전 충돌을 방지하기 위해 각자 작업한 내용을 공유 영역에 있는 Git등의 저장소에 빈번히 업로드함으로써 지속적 통합이 가능하도록 해 준다. MIT 라이선스를 따른다.

발생 시점

현재의 회사에서 배포를 젠킨스를 이용하여 배포를 진행한다.
신규 기능개발과 레거시를 청산하는 작업을 주로 해왔었어서 이쪽을 고치는게 우선은 아니었다.
그래서 모르고 있었던 것일수 있다.
에러 상황을 확인해보자

에러 상세

[Pipeline] End of Pipeline
java.lang.InterruptedException
    at java.base/java.lang.Object.wait(Native Method)
    at java.base/java.lang.Thread.join(Thread.java:1300)
    at java.base/java.lang.Thread.join(Thread.java:1375)
    at java.base/jdk.internal.reflect.GeneratedMethodAccessor774.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:93)
    at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:325)
    at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1213)
    at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1022)
    at org.codehaus.groovy.runtime.InvokerHelper.invokePojoMethod(InvokerHelper.java:913)
    at org.codehaus.groovy.runtime.InvokerHelper.invokeMethod(InvokerHelper.java:904)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodN(ScriptBytecodeAdapter.java:168)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodNSafe(ScriptBytecodeAdapter.java:176)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethodNSpreadSafe(ScriptBytecodeAdapter.java:183)
    at org.codehaus.groovy.runtime.ScriptBytecodeAdapter.invokeMethod0SpreadSafe(ScriptBytecodeAdapter.java:198)
    at org.hidetake.groovy.ssh.interaction.Interactions.waitForEndOfStream(Interactions.groovy:97)
    at org.hidetake.groovy.ssh.interaction.Interactions$waitForEndOfStream$2.call(Unknown Source)
    at org.hidetake.groovy.ssh.operation.Command.execute(Command.groovy:83)
    at org.hidetake.groovy.ssh.operation.Operation$execute$0.call(Unknown Source)
    at org.hidetake.groovy.ssh.session.execution.Command$Helper.execute(Command.groovy:50)
    at jdk.internal.reflect.GeneratedMethodAccessor951.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:93)
    at org.codehaus.groovy.runtime.callsite.StaticMetaMethodSite$StaticMetaMethodSiteNoUnwrapNoCoerce.invoke(StaticMetaMethodSite.java:151)
    at org.codehaus.groovy.runtime.callsite.StaticMetaMethodSite.call(StaticMetaMethodSite.java:91)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:141)
    at org.hidetake.groovy.ssh.session.execution.Command$Trait$Helper.execute(Command.groovy:30)
    at org.hidetake.groovy.ssh.session.execution.Command$Trait$Helper$execute$0.call(Unknown Source)
    at org.hidetake.groovy.ssh.session.SessionHandler.execute(SessionHandler.groovy)
    at jdk.internal.reflect.GeneratedMethodAccessor949.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at org.codehaus.groovy.runtime.callsite.PogoMetaMethodSite$PogoCachedMethodSite.invoke(PogoMetaMethodSite.java:169)
    at org.codehaus.groovy.runtime.callsite.PogoMetaMethodSite.call(PogoMetaMethodSite.java:71)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:133)
    at org.hidetake.groovy.ssh.session.execution.Command$Trait$Helper.execute(Command.groovy)
    at org.hidetake.groovy.ssh.session.execution.Command$Trait$Helper$execute.call(Unknown Source)
    at org.hidetake.groovy.ssh.session.SessionHandler.execute(SessionHandler.groovy)
    at jdk.internal.reflect.GeneratedMethodAccessor948.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:93)
    at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:325)
    at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:384)
    at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1022)
    at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.callCurrent(PogoMetaClassSite.java:69)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:166)
    at org.jenkinsci.plugins.sshsteps.SSHService$_executeCommand_closure3$_closure13.doCall(SSHService.groovy:182)
    at org.jenkinsci.plugins.sshsteps.SSHService$_executeCommand_closure3$_closure13.doCall(SSHService.groovy)
    at jdk.internal.reflect.GeneratedMethodAccessor947.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:93)
    at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:325)
    at org.codehaus.groovy.runtime.metaclass.ClosureMetaClass.invokeMethod(ClosureMetaClass.java:294)
    at groovy.lang.MetaClassImpl.invokeMethod(MetaClassImpl.java:1022)
    at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.call(PogoMetaClassSite.java:42)
    at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:48)
    at org.codehaus.groovy.runtime.callsite.PogoMetaClassSite.call(PogoMetaClassSite.java:57)
    at org.hidetake.groovy.ssh.util.Utility.callWithDelegate(Utility.groovy:17)
    at jdk.internal.reflect.GeneratedMethodAccessor427.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at org.codehaus.groovy.reflection.CachedMethod.invoke(CachedMethod.java:93)
    at groovy.lang.MetaMethod.doMethodInvoke(MetaMethod.java:325)
    at org.codehaus.groovy.runtime.callsite.StaticMetaMethodSite.invoke(StaticMetaMethodSite.java:46)
    at org.codehaus.groovy.runtime.callsite.StaticMetaMethodSite.callStatic(StaticMetaMethodSite.java:102)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callStatic(AbstractCallSite.java:214)
    at org.hidetake.groovy.ssh.session.SessionTask.wetRun(SessionTask.groovy:64)
    at jdk.internal.reflect.GeneratedMethodAccessor6430.invoke(Unknown Source)
    at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.base/java.lang.reflect.Method.invoke(Method.java:566)
    at org.codehaus.groovy.runtime.callsite.PogoMetaMethodSite$PogoCachedMethodSiteNoUnwrapNoCoerce.invoke(PogoMetaMethodSite.java:210)
    at org.codehaus.groovy.runtime.callsite.PogoMetaMethodSite.callCurrent(PogoMetaMethodSite.java:59)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.callCurrent(AbstractCallSite.java:158)
    at org.hidetake.groovy.ssh.session.SessionTask.call(SessionTask.groovy:48)
    at java_util_concurrent_Callable$call.call(Unknown Source)
    at org.hidetake.groovy.ssh.core.Service.run(Service.groovy:81)
    at org.hidetake.groovy.ssh.core.Service$run$1.call(Unknown Source)
    at org.jenkinsci.plugins.sshsteps.SSHService.executeCommand(SSHService.groovy:177)
    at org.jenkinsci.plugins.sshsteps.steps.CommandStep$Execution$CommandCallable.execute(CommandStep.java:84)
    at org.jenkinsci.plugins.sshsteps.util.SSHMasterToSlaveCallable.call(SSHMasterToSlaveCallable.java:32)
    at hudson.remoting.LocalChannel.call(LocalChannel.java:46)
    at org.jenkinsci.plugins.sshsteps.steps.CommandStep$Execution.run(CommandStep.java:72)
    at org.jenkinsci.plugins.sshsteps.util.SSHStepExecution.lambda$start$0(SSHStepExecution.java:84)
    at java.base/java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:515)
    at java.base/java.util.concurrent.FutureTask.run(FutureTask.java:264)
    at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
    at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
    at java.base/java.lang.Thread.run(Thread.java:829)
Finished: ABORTED

정확히 이 에러 윗부분까지는 클라이언트의 요청을 받아서 처리해주고 있다가
한방에 서버가 다운되어버렸다.
젠킨스에서의 배포 스크립트에도 문제가 있었다.
아래의 쉘 스크립트를 젠킨스가 도커 컨테이너 내부에서 실행해주게 만들었다.

#!/bin/bash
export JAVA_TOOL_OPTIONS="-Dfile.encoding='UTF8' -Duser.timezone=Asia/Seoul"
kill -9 $(lsof -t -i:8080)
cd /root/server/
git pull
git checkout $1
git pull origin $1
kill -9 $(lsof -t -i:8080)
mvn clean package -P dev

java -jar -Dspring.profiles.active=dev target/server-0.0.1-SNAPSHOT.jar

이러한 구성으로 된 쉘 스크립트를 통해 실행을 진행했기 때문에
jar를 즉각 실행하게 만들어서 로그가 그대로 젠킨스에 전부 찍히고,

왜? 🤔

그야 당연할것인데, 로그를 실시간으로 젠킨스가 배포 과정을 찍을텐데,

java -jar 명령어를 백그라운드로 실행시켜주지를 않았다.

젠킨스의 배포는 항상 finished상태가 나오질 않는 상태였다.

항상 이상태였다 ㅋㅋㅋ

gif 처음만들어봤는데 재밌네..
이부분에서 로그가 과다하게 많이 쌓이게 되어 에러를 내뱉고
was가 죽어버린 상태가 되어버렸다. (비정상적 셧다운)

해결

JENKINS-45150 large console logging can take Jenkins down or affecting performance - Jenkins Jira
검색을 진행해보니 위와같은 내용들도 얻을 수 있었다.
그래서 해결과정의 순서를 생각한 방식은 다음과 같다.

1. 젠킨스는 배포를 끝내서
   이러한 화면을 만들어주어야 한다.

2. 스프링 애플리케이션의 배포 스크립트를 바꿔주어야 한다. (java -jar를 백그라운드로)

이렇게 하면 되겠다!

그래서 전부 바꿔주게 된다.

#!/bin/bash
export JAVA_TOOL_OPTIONS="-Dfile.encoding='UTF8' -Duser.timezone=Asia/Seoul"
kill -15 $(lsof -t -i:8080)
cd /root/server/
git pull
git checkout $1
git pull origin $1
kill -15 $(lsof -t -i:8080)
mvn clean package -P dev

nohup java -jar -Dspring.profiles.active=dev target/server-0.0.1-SNAPSHOT.jar > ~/app.log 2>&1 &

echo "Deploy Success"

nohup을 이용한 중단없이 실행해주고 젠킨스는 밖으로 빠져나와야 했기 때문에
이 명령어를 선택하고 실행해주었다.

그와 동시에 간단하게 라이브로 볼수있게끔 기본적으로 생성되는 nohup.out을 혹시몰라 만들어둔채로 마무리를 해놓았다.

그리고 kill명령어를 15로 바꾸었는데,
9는 강제종료기 때문에 진행중이던 작업을 즉시 종료하고 데이터도 저장하지 않는다.
15는 자신이 하던 작업을 모두 안전하게 종료하는 절차를 밟는다.
메모리상에 있는 데이터와 각종 설정/환경 파일을 안전하게 저장한 후 프로세스를 종료한다.
15로 한다고 한들, 종료 명령어를 주게되면, 어떤 클라이언트가 요청을 보내서 작업중인 데이터도 끊어질 것이다.
그래서 spring에서 제공하는 graceful shutdown을 적용하고 kill -15를 같이 붙여주었다.
graceful shutdown은 지금 포스팅에서 다루지 않겠다.
이렇게 해서 젠킨스의 로그 과다 적재로 서버가 죽는 현상을 제거시키게 되었다.

정리

이렇게 되어 젠킨스에 기존에 (내가 건드리지 않은) 잘못되게 설정되어 있던 것을 고치게 되니
괜찮다.
그러면서 동시에 툴도 툴마다의 각자의 할일이 있는 것인데,
CI/CD를 위한 툴에서 로그 모니터링까지 하고 있었으니 과다적재로 에러를 뱉는다는 것은
어찌보면 당연한 것이었을 수 있다고 나는 생각한다.🔥