[ 5.4.3 / P369 ] 젠킨스 블루그린 파이프라인 빌드 실패

nmin11 commented 2 years ago

중요 이슈를 받기 어려운 사항은 다음과 같습니다.

책에 사용되는 환경 및 기술과 관련된 질문
또는 책에서 구성한 환경외 조건에서 발생한 이슈
goto
1. 쿠버네티스 오픈 채팅: https://open.kakao.com/o/gxSooElb (암호: kubectl)
2. 쿠버네티스 유저 그룹: https://www.facebook.com/groups/k8skr
개개인의 환경에 영향을 받는 vagrant 에러(error)와 관련된 이슈
하지만 다음의 사항에 모두 해당 한다면 이슈를 부탁드립니다.
- [ ] 초기화된(새로 설치) 노트북(또는 PC)
- [ ] 책에서 제시한 프로그램과 동일한 버전 설치
- [ ] 할리스(IP가 겹침)를 제외한 카페 또는 집에서 실행
- [ ] 2대 이상 동일하게 문제가 발생함
책의 오타 및 형식의 오류 이와 같은 경우에는 다음의 절차를 따라서 진행
- [ ] 길벗 홈페이지에 접속
- [ ] 고객센터 클릭
- [ ] 1:1문의 접속 후에 오류 및 문의 사항을 제보

위의 사항 외에 이슈라면 가능한 빨리(평균적으로 1일 이내) 회신드리도록 하겠습니다.

[ 내용 ]

책의 내용대로 dpy-pl-blue-green 파이프라인을 생성한 뒤 Build Now 버튼 클릭 시

블루그린 파이프라인 빌드 에러

이와 같이 'deploy configmap and deployment' stage에서 빌드 에러가 발생하고,
로그는 다음과 같이 출력됩니다.

java.io.IOException: Timed out waiting for websocket connection. You should increase the value of system property org.csanchez.jenkins.plugins.kubernetes.pipeline.ContainerExecDecorator.websocketConnectionTimeout currently set at 30 seconds
    at org.csanchez.jenkins.plugins.kubernetes.pipeline.ContainerExecDecorator$1.doLaunch(ContainerExecDecorator.java:441)
    at org.csanchez.jenkins.plugins.kubernetes.pipeline.ContainerExecDecorator$1.launch(ContainerExecDecorator.java:336)
    at hudson.Launcher$ProcStarter.start(Launcher.java:508)
    at org.jenkinsci.plugins.durabletask.BourneShellScript.launchWithCookie(BourneShellScript.java:236)
    at org.jenkinsci.plugins.durabletask.FileMonitoringTask.launch(FileMonitoringTask.java:103)
    at org.jenkinsci.plugins.workflow.steps.durable_task.DurableTaskStep$Execution.start(DurableTaskStep.java:320)
    at org.jenkinsci.plugins.workflow.cps.DSL.invokeStep(DSL.java:319)
    at org.jenkinsci.plugins.workflow.cps.DSL.invokeMethod(DSL.java:193)
    at org.jenkinsci.plugins.workflow.cps.CpsScript.invokeMethod(CpsScript.java:122)
    at sun.reflect.NativeMethodAccessorImpl.invoke0(Native Method)
    at sun.reflect.NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:62)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    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.callsite.PogoMetaClassSite.call(PogoMetaClassSite.java:42)
    at org.codehaus.groovy.runtime.callsite.CallSiteArray.defaultCall(CallSiteArray.java:48)
    at org.codehaus.groovy.runtime.callsite.AbstractCallSite.call(AbstractCallSite.java:113)
    at org.kohsuke.groovy.sandbox.impl.Checker$1.call(Checker.java:163)
    at org.kohsuke.groovy.sandbox.GroovyInterceptor.onMethodCall(GroovyInterceptor.java:23)
    at org.jenkinsci.plugins.scriptsecurity.sandbox.groovy.SandboxInterceptor.onMethodCall(SandboxInterceptor.java:158)
    at org.kohsuke.groovy.sandbox.impl.Checker$1.call(Checker.java:161)
    at org.kohsuke.groovy.sandbox.impl.Checker.checkedCall(Checker.java:165)
    at org.kohsuke.groovy.sandbox.impl.Checker.checkedCall(Checker.java:135)
    at org.kohsuke.groovy.sandbox.impl.Checker.checkedCall(Checker.java:135)
    at org.kohsuke.groovy.sandbox.impl.Checker.checkedCall(Checker.java:135)
    at com.cloudbees.groovy.cps.sandbox.SandboxInvoker.methodCall(SandboxInvoker.java:17)
    at WorkflowScript.run(WorkflowScript:50)
    at ___cps.transform___(Native Method)
    at com.cloudbees.groovy.cps.impl.ContinuationGroup.methodCall(ContinuationGroup.java:86)
    at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.dispatchOrArg(FunctionCallBlock.java:113)
    at com.cloudbees.groovy.cps.impl.FunctionCallBlock$ContinuationImpl.fixArg(FunctionCallBlock.java:83)
    at sun.reflect.GeneratedMethodAccessor314.invoke(Unknown Source)
    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
    at java.lang.reflect.Method.invoke(Method.java:498)
    at com.cloudbees.groovy.cps.impl.ContinuationPtr$ContinuationImpl.receive(ContinuationPtr.java:72)
    at com.cloudbees.groovy.cps.impl.ConstantBlock.eval(ConstantBlock.java:21)
    at com.cloudbees.groovy.cps.Next.step(Next.java:83)
    at com.cloudbees.groovy.cps.Continuable$1.call(Continuable.java:174)
    at com.cloudbees.groovy.cps.Continuable$1.call(Continuable.java:163)
    at org.codehaus.groovy.runtime.GroovyCategorySupport$ThreadCategoryInfo.use(GroovyCategorySupport.java:129)
    at org.codehaus.groovy.runtime.GroovyCategorySupport.use(GroovyCategorySupport.java:268)
    at com.cloudbees.groovy.cps.Continuable.run0(Continuable.java:163)
    at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.access$001(SandboxContinuable.java:18)
    at org.jenkinsci.plugins.workflow.cps.SandboxContinuable.run0(SandboxContinuable.java:51)
    at org.jenkinsci.plugins.workflow.cps.CpsThread.runNextChunk(CpsThread.java:185)
    at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup.run(CpsThreadGroup.java:403)
    at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup.access$400(CpsThreadGroup.java:97)
    at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:315)
    at org.jenkinsci.plugins.workflow.cps.CpsThreadGroup$2.call(CpsThreadGroup.java:279)
    at org.jenkinsci.plugins.workflow.cps.CpsVmExecutorService$2.call(CpsVmExecutorService.java:67)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at hudson.remoting.SingleLaneExecutorService$1.run(SingleLaneExecutorService.java:136)
    at jenkins.util.ContextResettingExecutorService$1.run(ContextResettingExecutorService.java:28)
    at jenkins.security.ImpersonatingExecutorService$1.run(ImpersonatingExecutorService.java:59)
    at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
    at java.util.concurrent.FutureTask.run(FutureTask.java:266)
    at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
    at java.lang.Thread.run(Thread.java:748)

에러 문구 자체는 웹소켓 연결 시간이 30초로 설정되어 있는데 이를 초과했으므로 실패했다는 것으로 보여지는데,
근본적으로는 'deploy configmap and deployment' stage의 셸 스크립트를 실행하던 중에 에러가 발생한 것 같습니다.
혹시 관련해서 더 자세하게 로그를 추적하거나 아니면 다른 해결 방법이 있을까요?

sysnet4admin commented 2 years ago

안녕하세요

해당 현상에 대해서 확인 중입니다. 일단은 기존에 플러그인 버전을 고정한 것과 연관이 있는 것으로 파악하고 있습니다.

감사합니다.

sysnet4admin commented 2 years ago

쿠버네티스.플러그인과 에이전트쪽 통신의 문제와 연관된 것으로 보여져 조사 중입니다. 주말 내로 파악하여 해결하는 것을 목표로 하고 있습니다.

[ 관련 로그 ]

[root@w2-k8s ~]# tail -f  /var/log/containers/dpy-pl-blue-green-3-6dj8b-fqrmm-wkxhr_default_jnlp-4ea9ad5ca0c7f644d3902a5e9d07d977a4757cd3bd6b302cf4e52899b3fc9d1e.log 
{"log":"Apr 14, 2022 11:23:18 AM hudson.remoting.jnlp.Main$CuiListener status\n","stream":"stderr","time":"2022-04-14T11:23:18.781565132Z"}
{"log":"INFO: Handshaking\n","stream":"stderr","time":"2022-04-14T11:23:18.781583513Z"}
{"log":"Apr 14, 2022 11:23:18 AM hudson.remoting.jnlp.Main$CuiListener status\n","stream":"stderr","time":"2022-04-14T11:23:18.786153734Z"}
{"log":"INFO: Connecting to jenkins-agent:50000\n","stream":"stderr","time":"2022-04-14T11:23:18.786174132Z"}
{"log":"Apr 14, 2022 11:23:18 AM hudson.remoting.jnlp.Main$CuiListener status\n","stream":"stderr","time":"2022-04-14T11:23:18.799443894Z"}
{"log":"INFO: Trying protocol: JNLP4-connect\n","stream":"stderr","time":"2022-04-14T11:23:18.79947136Z"}
{"log":"Apr 14, 2022 11:23:19 AM hudson.remoting.jnlp.Main$CuiListener status\n","stream":"stderr","time":"2022-04-14T11:23:19.116634725Z"}
{"log":"INFO: Remote identity confirmed: eb:df:cb:ae:d1:6d:67:e4:f6:c8:d5:48:f7:38:45:89\n","stream":"stderr","time":"2022-04-14T11:23:19.116665851Z"}
{"log":"Apr 14, 2022 11:23:20 AM hudson.remoting.jnlp.Main$CuiListener status\n","stream":"stderr","time":"2022-04-14T11:23:20.522543442Z"}
{"log":"INFO: Connected\n","stream":"stderr","time":"2022-04-14T11:23:20.522576857Z"}
{"log":"Apr 14, 2022 11:24:11 AM org.csanchez.jenkins.plugins.kubernetes.KubernetesSlave$SlaveDisconnector call\n","stream":"stderr","time":"2022-04-14T11:24:11.121796431Z"}
{"log":"INFO: Disabled slave engine reconnects.\n","stream":"stderr","time":"2022-04-14T11:24:11.121840909Z"}
{"log":"Apr 14, 2022 11:24:11 AM hudson.util.ProcessTree get\n","stream":"stderr","time":"2022-04-14T11:24:11.233294752Z"}
{"log":"WARNING: Error while determining if vetoers exist\n","stream":"stderr","time":"2022-04-14T11:24:11.233331754Z"}
{"log":"hudson.remoting.RemotingSystemException: hudson.remoting.ChannelClosedException: Channel \"unknown\": Protocol stack cannot write data anymore. It is not open for write\n","stream":"stderr","time":"2022-04-14T11:24:11.233334404Z"}
{"log":"\u0009at hudson.remoting.RemoteInvocationHandler.invoke(RemoteInvocationHandler.java:301)\n","stream":"stderr","time":"2022-04-14T11:24:11.233338652Z"}
{"log":"\u0009at com.sun.proxy.$Proxy5.fetch3(Unknown Source)\n","stream":"stderr","time":"2022-04-14T11:24:11.23334104Z"}
{"log":"\u0009at hudson.remoting.RemoteClassLoader.findClass(RemoteClassLoader.java:211)\n","stream":"stderr","time":"2022-04-14T11:24:11.233343228Z"}
{"log":"\u0009at java.lang.ClassLoader.loadClass(ClassLoader.java:419)\n","stream":"stderr","time":"2022-04-14T11:24:11.233345405Z"}
{"log":"\u0009at java.lang.ClassLoader.loadClass(ClassLoader.java:352)\n","stream":"stderr","time":"2022-04-14T11:24:11.233347584Z"}
{"log":"\u0009at jenkins.agents.AgentComputerUtil.getChannelToMaster(AgentComputerUtil.java:48)\n","stream":"stderr","time":"2022-04-14T11:24:11.233349675Z"}
{"log":"\u0009at hudson.util.ProcessTree.get(ProcessTree.java:432)\n","stream":"stderr","time":"2022-04-14T11:24:11.233351736Z"}
{"log":"\u0009at hudson.Launcher$RemoteLauncher$KillTask.call(Launcher.java:1164)\n","stream":"stderr","time":"2022-04-14T11:24:11.233353773Z"}
{"log":"\u0009at hudson.Launcher$RemoteLauncher$KillTask.call(Launcher.java:1155)\n","stream":"stderr","time":"2022-04-14T11:24:11.233355806Z"}
{"log":"\u0009at hudson.remoting.UserRequest.perform(UserRequest.java:211)\n","stream":"stderr","time":"2022-04-14T11:24:11.233357858Z"}
{"log":"\u0009at hudson.remoting.UserRequest.perform(UserRequest.java:54)\n","stream":"stderr","time":"2022-04-14T11:24:11.233359965Z"}
{"log":"\u0009at hudson.remoting.Request$2.run(Request.java:369)\n","stream":"stderr","time":"2022-04-14T11:24:11.233362018Z"}
{"log":"\u0009at hudson.remoting.InterceptingExecutorService$1.call(InterceptingExecutorService.java:72)\n","stream":"stderr","time":"2022-04-14T11:24:11.233364104Z"}
{"log":"\u0009at java.util.concurrent.FutureTask.run(FutureTask.java:266)\n","stream":"stderr","time":"2022-04-14T11:24:11.233366172Z"}
{"log":"\u0009at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)\n","stream":"stderr","time":"2022-04-14T11:24:11.233368205Z"}
{"log":"\u0009at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)\n","stream":"stderr","time":"2022-04-14T11:24:11.233370284Z"}
{"log":"\u0009at hudson.remoting.Engine$1.lambda$newThread$0(Engine.java:117)\n","stream":"stderr","time":"2022-04-14T11:24:11.233372389Z"}
{"log":"\u0009at java.lang.Thread.run(Thread.java:748)\n","stream":"stderr","time":"2022-04-14T11:24:11.233374447Z"}
{"log":"Caused by: hudson.remoting.ChannelClosedException: Channel \"unknown\": Protocol stack cannot write data anymore. It is not open for write\n","stream":"stderr","time":"2022-04-14T11:24:11.233376562Z"}
{"log":"\u0009at org.jenkinsci.remoting.protocol.impl.ChannelApplicationLayer$ByteBufferCommandTransport.write(ChannelApplicationLayer.java:305)\n","stream":"stderr","time":"2022-04-14T11:24:11.233378824Z"}
{"log":"\u0009at hudson.remoting.AbstractByteBufferCommandTransport.write(AbstractByteBufferCommandTransport.java:304)\n","stream":"stderr","time":"2022-04-14T11:24:11.233381085Z"}
{"log":"\u0009at hudson.remoting.Channel.send(Channel.java:764)\n","stream":"stderr","time":"2022-04-14T11:24:11.233383229Z"}
{"log":"\u0009at hudson.remoting.Request.call(Request.java:160)\n","stream":"stderr","time":"2022-04-14T11:24:11.233385243Z"}
{"log":"\u0009at hudson.remoting.RemoteInvocationHandler.invoke(RemoteInvocationHandler.java:288)\n","stream":"stderr","time":"2022-04-14T11:24:11.233398771Z"}
{"log":"\u0009... 17 more\n","stream":"stderr","time":"2022-04-14T11:24:11.233402Z"}
{"log":"\n","stream":"stderr","time":"2022-04-14T11:24:11.233404072Z"}
{"log":"Apr 14, 2022 11:24:11 AM hudson.remoting.jnlp.Main$CuiListener status\n","stream":"stderr","time":"2022-04-14T11:24:11.269684818Z"}
{"log":"INFO: Terminated\n","stream":"stderr","time":"2022-04-14T11:24:11.269711804Z"}

nmin11 commented 2 years ago

확인해주셔서 감사드리고 주말까지 수고해주신다니 또한 너무나 감사드립니다.

sysnet4admin commented 2 years ago

이슈 내용

일전에 issue#2에서 젠킨스에서 설치되는 플러그인을 고정했습니다. 고정된 플러그인 리스트는 다음의 경로에서 확인 가능합니다.

그런데 이미 고정된 버전에서, 의존성(Dependency)을 변경하는 경우에는 이에 따라 플러그인이 업데이트 되는 것을 확인하였습니다.

이슈에 대한 자세한 설명

이를 그림으로 설명하면 다음과 같습니다.

1. 고정된 버전 현재는 compatible을 통해 업데이트되기 전입니다. (젠킨스 관리 - 플러그인 관리 - 설치된 플러그인 목록)

2.compatible로 업데이트를 진행 하지만 업데이트 이후에...

3.업데이트 된 버전 kubernetes-client-api-plugin의 버전이 바뀐 것을 확인합니다. (젠킨스 관리 - 플러그인 관리 - 설치된 플러그인 목록)

임시 해결책(Workaround)

kubernetes-client-api-plugin의 버전을 5.4.1으로 다운그레이드 버튼을 눌러 버전을 내리면 현재의 문제는 일단 해결됩니다.

좀 더 permanent한 솔루션은 다음 주내로 제공하도록 하겠습니다.

이와 관련된 로그는 다음과 같습니다.

[root@m-k8s ~]# k logs jenkins-6b6f9b8675-stb2v jenkins
<snipped>
2022-04-16 12:30:24.162+0000 [id=32]    SEVERE  hudson.triggers.SafeTimerTask#run: Timer task org.csanchez.jenkins.plugins.kubernetes.KubernetesClientProvider$UpdateConnectionCount@18a1b36c failed
java.lang.NoSuchMethodError: io.fabric8.kubernetes.client.HttpClientAware.getHttpClient()Lokhttp3/OkHttpClient;
        at org.csanchez.jenkins.plugins.kubernetes.KubernetesClientProvider$UpdateConnectionCount.doRun(KubernetesClientProvider.java:269)
        at hudson.triggers.SafeTimerTask.run(SafeTimerTask.java:91)
        at jenkins.security.ImpersonatingScheduledExecutorService$1.run(ImpersonatingScheduledExecutorService.java:58)
        at java.util.concurrent.Executors$RunnableAdapter.call(Executors.java:511)
        at java.util.concurrent.FutureTask.runAndReset(FutureTask.java:308)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.access$301(ScheduledThreadPoolExecutor.java:180)
        at java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(ScheduledThreadPoolExecutor.java:294)
        at java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
        at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
        at java.lang.Thread.run(Thread.java:748)

해결 된 것 확인

버전 변경 확인

Pipeline dpy-pl-blue-green을 다시 build now 함

영구적인(permanent) 해결 방법

기존에 https://updates.jenkins.io/update-center.json 을 통해서 받던 젠킨스의 플러그인 정보(update-center.json)를 직접 제공하도록 코드를 변경하였습니다. 이를 통해 현재 이슈 및 #21 가 함께 해결 됩니다.

현재 이슈는 1주일간 모니터링 된 후에 Close 됩니다. 감사합니다. 조 훈, 심근우, 문성주 드림

sysnet4admin / _Book_k8sInfra