I was able to reduce the first 10 sec interval by setting this
```
export
AGENT_BOOTSTRAPPER_JVM_ARGS="-Dagent.bootstrapper.wait.time.before.relaunch.in.ms=200
```
On Tuesday, February 8, 2022 at 12:07:59 AM UTC+5:30 deepak jain wrote:
>
> Gocd elastic agent takes upto 90 sec to complete the bootstrap in many
> cases. we are using k8s elastic agent in gocd.
> - after starting to search for high bootstrap time i found out the main
> culprit was pluing loader. it aws loading plugin sequentially. so after
> removing plugin which we don't need, i was able to bring bootup time to 36
> second.
>
> ```
> jvm 1 | 2022-02-07 16:27:31,128 [stdout] - 2022-02-07 16:27:31,127 INFO
> [main] DefaultPluginJarChangeListener:67 - Plugin load starting:
> /go/plugins/external/github_feature_branch.jar
> jvm 1 | 2022-02-07 16:27:34,774 [stdout] - 2022-02-07 16:27:34,773
> ERROR [scheduler-3] RemotingClient:166 - Server responded to action `ping`
> with: status[422 Unprocessable Entity], body[{
> jvm 1 | 2022-02-07 16:27:34,774 [stdout] - "message" : "Agent [Agent
> [prod-default-gocd-agent-37129320-c0ff-400b-adcf-0cbcfb07456e, 10.1.134.86,
> 226c9178-3fe6-49e0-93fa-e5884eee8bca, null]] has no cookie set; nested
> exception is com.thoughtworks.go.server.service.AgentNoCookieSetException:
> Agent [Agent [prod-default-gocd-agent-37129320-c0ff-400b-adcf-0cbcfb07456e,
> 10.1.134.86, 226c9178-3fe6-49e0-93fa-e5884eee8bca, null]] has no cookie set"
> jvm 1 | 2022-02-07 16:27:34,774 [stdout] - }]
> jvm 1 | 2022-02-07 16:27:34,774 [stdout] - 2022-02-07 16:27:34,773
> ERROR [scheduler-3] AgentHTTPClientController:114 - Error occurred when
> agent tried to ping server:
> jvm 1 | 2022-02-07 16:27:34,774 [stdout] - java.lang.RuntimeException:
> org.apache.http.client.ClientProtocolException: The server returned status
> code 422. Possible reasons include:
> jvm 1 | 2022-02-07 16:27:34,774 [stdout] - - This agent has been
> deleted from the configuration
> jvm 1 | 2022-02-07 16:27:34,774 [stdout] - - This agent is pending
> approval
> jvm 1 | 2022-02-07 16:27:34,774 [stdout] - - There is possibly a
> reverse proxy (or load balancer) that has been misconfigured. See
> https://docs.gocd.org/21.3.0/installation/configure-reverse-proxy.html#agents-and-reverse-proxies
>
> for details.
> jvm 1 | 2022-02-07 16:27:34,774 [stdout] - at
> com.thoughtworks.go.agent.RemotingClient.post(RemotingClient.java:118)
> jvm 1 | 2022-02-07 16:27:34,774 [stdout] - at
> com.thoughtworks.go.agent.RemotingClient.ping(RemotingClient.java:74)
> jvm 1 | 2022-02-07 16:27:34,774 [stdout] - at
> com.thoughtworks.go.agent.AgentHTTPClientController.ping(AgentHTTPClientController.java:109)
> jvm 1 | 2022-02-07 16:27:34,774 [stdout] - at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native
> Method)
> jvm 1 | 2022-02-07 16:27:34,774 [stdout] - at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown
> Source)
> jvm 1 | 2022-02-07 16:27:34,774 [stdout] - at
> java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown
> Source)
> jvm 1 | 2022-02-07 16:27:34,774 [stdout] - at
> java.base/java.lang.reflect.Method.invoke(Unknown Source)
> jvm 1 | 2022-02-07 16:27:34,774 [stdout] - at
> org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:65)
> jvm 1 | 2022-02-07 16:27:34,775 [stdout] - at
> org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
> jvm 1 | 2022-02-07 16:27:34,775 [stdout] - at
> java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown
> Source)
> jvm 1 | 2022-02-07 16:27:34,775 [stdout] - at
> java.base/java.util.concurrent.FutureTask.runAndReset(Unknown Source)
> jvm 1 | 2022-02-07 16:27:34,775 [stdout] - at
> java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown
>
> Source)
> jvm 1 | 2022-02-07 16:27:34,775 [stdout] - at
> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
> jvm 1 | 2022-02-07 16:27:34,775 [stdout] - at
> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
> jvm 1 | 2022-02-07 16:27:34,775 [stdout] - at
> java.base/java.lang.Thread.run(Unknown Source)
> jvm 1 | 2022-02-07 16:27:34,775 [stdout] - Caused by:
> org.apache.http.client.ClientProtocolException: The server returned status
> code 422. Possible reasons include:
> jvm 1 | 2022-02-07 16:27:34,775 [stdout] - - This agent has been
> deleted from the configuration
> jvm 1 | 2022-02-07 16:27:34,775 [stdout] - - This agent is pending
> approval
> jvm 1 | 2022-02-07 16:27:34,775 [stdout] - - There is possibly a
> reverse proxy (or load balancer) that has been misconfigured. See
> https://docs.gocd.org/21.3.0/installation/configure-reverse-proxy.html#agents-and-reverse-proxies
>
> for details.
> jvm 1 | 2022-02-07 16:27:34,775 [stdout] - at
> com.thoughtworks.go.agent.RemotingClient.validateResponse(RemotingClient.java:141)
> jvm 1 | 2022-02-07 16:27:34,775 [stdout] - at
> com.thoughtworks.go.agent.RemotingClient.post(RemotingClient.java:114)
> jvm 1 | 2022-02-07 16:27:34,775 [stdout] - ... 14 common frames
> omitted
> jvm 1 | 2022-02-07 16:27:35,544 [stdout] - 2022-02-07 16:27:35,544 INFO
> [main] DefaultPluginJarChangeListener:74 - Plugin load finished:
> /go/plugins/external/github_feature_branch.jar
> jvm 1 | 2022-02-07 16:27:35,553 [stdout] - 2022-02-07 16:27:35,552 INFO
> [main] DefaultPluginJarChangeListener:67 - Plugin load starting:
> /go/plugins/external/git-path-material-plugin.jar
> jvm 1 | 2022-02-07 16:27:35,674 [stdout] - 2022-02-07 16:27:35,674
> INFO [main] p.G.c.t.g.s.p.GitPathMaterialPlugin:72
> [plugin-GitPathMaterial] - Loading GitPathMaterialPlugin...
> jvm 1 | 2022-02-07 16:27:39,782 [stdout] - 2022-02-07 16:27:39,781
> ERROR [scheduler-3] RemotingClient:166 - Server responded to action `ping`
> with: status[422 Unprocessable Entity], body[{
> jvm 1 | 2022-02-07 16:27:39,782 [stdout] - "message" : "Agent [Agent
> [prod-default-gocd-agent-37129320-c0ff-400b-adcf-0cbcfb07456e, 10.1.134.86,
> 226c9178-3fe6-49e0-93fa-e5884eee8bca, null]] has no cookie set; nested
> exception is com.thoughtworks.go.server.service.AgentNoCookieSetException:
> Agent [Agent [prod-default-gocd-agent-37129320-c0ff-400b-adcf-0cbcfb07456e,
> 10.1.134.86, 226c9178-3fe6-49e0-93fa-e5884eee8bca, null]] has no cookie set"
> jvm 1 | 2022-02-07 16:27:39,782 [stdout] - }]
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - 2022-02-07 16:27:39,782
> ERROR [scheduler-3] AgentHTTPClientController:114 - Error occurred when
> agent tried to ping server:
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - java.lang.RuntimeException:
> org.apache.http.client.ClientProtocolException: The server returned status
> code 422. Possible reasons include:
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - - This agent has been
> deleted from the configuration
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - - This agent is pending
> approval
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - - There is possibly a
> reverse proxy (or load balancer) that has been misconfigured. See
> https://docs.gocd.org/21.3.0/installation/configure-reverse-proxy.html#agents-and-reverse-proxies
>
> for details.
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - at
> com.thoughtworks.go.agent.RemotingClient.post(RemotingClient.java:118)
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - at
> com.thoughtworks.go.agent.RemotingClient.ping(RemotingClient.java:74)
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - at
> com.thoughtworks.go.agent.AgentHTTPClientController.ping(AgentHTTPClientController.java:109)
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke0(Native
> Method)
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - at
> java.base/jdk.internal.reflect.NativeMethodAccessorImpl.invoke(Unknown
> Source)
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - at
> java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(Unknown
> Source)
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - at
> java.base/java.lang.reflect.Method.invoke(Unknown Source)
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - at
> org.springframework.scheduling.support.ScheduledMethodRunnable.run(ScheduledMethodRunnable.java:65)
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - at
> org.springframework.scheduling.support.DelegatingErrorHandlingRunnable.run(DelegatingErrorHandlingRunnable.java:54)
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - at
> java.base/java.util.concurrent.Executors$RunnableAdapter.call(Unknown
> Source)
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - at
> java.base/java.util.concurrent.FutureTask.runAndReset(Unknown Source)
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - at
> java.base/java.util.concurrent.ScheduledThreadPoolExecutor$ScheduledFutureTask.run(Unknown
>
> Source)
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - at
> java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(Unknown Source)
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - at
> java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(Unknown Source)
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - at
> java.base/java.lang.Thread.run(Unknown Source)
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - Caused by:
> org.apache.http.client.ClientProtocolException: The server returned status
> code 422. Possible reasons include:
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - - This agent has been
> deleted from the configuration
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - - This agent is pending
> approval
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - - There is possibly a
> reverse proxy (or load balancer) that has been misconfigured. See
> https://docs.gocd.org/21.3.0/installation/configure-reverse-proxy.html#agents-and-reverse-proxies
>
> for details.
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - at
> com.thoughtworks.go.agent.RemotingClient.validateResponse(RemotingClient.java:141)
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - at
> com.thoughtworks.go.agent.RemotingClient.post(RemotingClient.java:114)
> jvm 1 | 2022-02-07 16:27:39,783 [stdout] - ... 14 common frames
> omitted
> jvm 1 | 2022-02-07 16:27:40,213 [stdout] - 2022-02-07 16:27:40,212 INFO
> [main] DefaultPluginJarChangeListener:74 - Plugin load finished:
> /go/plugins/external/git-path-material-plugin.jar
> ```
>
> - after above steps there 2 log lines which had 10 sec gap each if we can
> tune it, it can reduce the bootstrap time considerably.
> 1st one is
>
> ```
> jvm 1 | 2022-02-07 16:26:47,893 INFO [WrapperJarAppMain]
> DefaultAgentLauncherCreatorImpl:87 - Attempt No: 1 to cleanup launcher temp
> files
> jvm 1 | 2022-02-07 16:26:47,919 INFO [WrapperJarAppMain]
> AgentBootstrapper:104 - Waiting for 10000 ms before re-launch....
> jvm 1 | 2022-02-07 16:26:58,018 INFO [WrapperJarAppMain]
> DefaultAgentLauncherCreatorImpl:67 - Attempting to load
> com.thoughtworks.go.agent.launcher.AgentLauncherImpl as specified by
> manifest key Go-Agent-Launcher-Class
> ```
>
> i found out the system property which we can use to reduce this time. but
> still haven't tried it
>
> 2nd one is
> ```
> jvm 1 | 2022-02-07 16:27:40,230 [stdout] - 2022-02-07 16:27:40,230 INFO
> [scheduler-1] AgentHTTPClientController:142 - Got cookie:
> 2df451e8-a5fb-4d9a-b8e2-e38efb52b27f
> jvm 1 | 2022-02-07 16:27:50,362 [stdout] - 2022-02-07 16:27:50,361 INFO
> [scheduler-1] HttpService:125 - Got back 200 from server
> ```
>
> i couldn't find out as to why there is this 10 sec gap. so reason of this
> ticket to understand this 10 sec wait time.
>
> * Go Version: 21.3.0 (13067-4c4bb4780eb0d3fc4cacfc4cfcc0b07e2eaf0595)
>
--
You received this message because you are subscribed to the Google Groups
"go-cd" group.
To unsubscribe from this group and stop receiving emails from it, send an email
to go-cd+unsubscr...@googlegroups.com.
To view this discussion on the web visit
https://groups.google.com/d/msgid/go-cd/c731d656-30de-44fe-87b6-d549b44723edn%40googlegroups.com.
