Hi Jainee,

Im using k8s elastic agent as well.  Can you tell me exactly where you set 
this?  On a ec2 agent its normally set in /etc/default/....

On Sunday, February 13, 2022 at 3:44:14 AM UTC-5 [email protected] wrote:

> 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 [email protected].
To view this discussion on the web visit 
https://groups.google.com/d/msgid/go-cd/add9ac65-298a-4049-a058-1f393125b682n%40googlegroups.com.

Reply via email to