Automated Restarts of Environments failing when run from Autosys

book

Article ID: 222538

calendar_today

Updated On:

Products

Service Virtualization

Issue/Introduction

 

This issue seems to have started with 10.6. However, I don't believe it is a DevTest issue, as much as something happening with the timing of the batch process? 
Attached are the registry logs. I have no simulator logs because one of the symptoms of the restart failure is a failure to generate a tmp folder for the simulator machines.
The first simulator comes online and shortly after we get a wireframe error message from the portal and everything fails when trying to view the Server status from the Portal.
A manual restart of the simulator fixes everything.  This is an error from row 2009 of the registry log:

2021-08-10 16:24:40,825Z (11:24) [qtp528917282-127] ERROR org.springframework.boot.web.support.ErrorPageFilter - Cannot forward to error page for request [/api/v1/serverstatuses] 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
2021-08-10 16:24:50,742Z (11:24) [ServerRequestResponder 3] INFO  com.itko.lisa.coordinator.TestRegistryImpl - getSimulator - simulator not found for tcp://<HOSTNAME>:2014/Sim3 (zlis010)@Default
2021-08-10 16:24:50,744Z (11:24) [ServerRequestResponder 3] INFO  com.itko.lisa.coordinator.TestRegistryImpl - getSimulator - simulator not found for tcp://<HOSTNAME>:2014/Sim3 (zlis010)@Default
2021-08-10 16:24:50,744Z (11:24) [ServerRequestResponder 3] INFO  com.itko.lisa.coordinator.TestRegistryImpl - Added simulator tcp://<HOSTNAME>:2014/Sim3 (zlis010) to lab Default
2021-08-10 16:24:50,825Z (11:24) [Monitor thread 1] INFO  com.itko.lisa.net.ClientBase   - No response from remote server SimulatorServerClient [sn=tcp://<HOSTNAME>:2014/Sim2 (zlis009)]
2021-08-10 16:24:50,825Z (11:24) [Monitor thread 1] WARN  com.itko.lisa.coordinator.LabServerMonitor - Monitored object - alert failed or no pulse SimulatorServerClient [sn=tcp://<HOSTNAME>:2014/Sim2 (zlis009)]
2021-08-10 16:24:50,825Z (11:24) [Monitor thread 1] WARN  com.itko.lisa.coordinator.LabServerMonitor - Removed object from server list of lab Default : SimulatorServerClient [sn=tcp://<HOSTNAME>:2014/Sim2 (zlis009)]
2021-08-10 16:24:50,830Z (11:24) [Monitor thread 1] INFO  System.out                     - Aug 10, 2021 11:24:50 AM com.squareup.okhttp.internal.Platform$JdkWithJettyBootPlatform getSelectedProtocol
2021-08-10 16:24:50,830Z (11:24) [Monitor thread 1] INFO  System.out                     - INFO: ALPN callback dropped: SPDY and HTTP/2 are disabled. Is alpn-boot on the boot class path?
2021-08-10 16:25:00,827Z (11:25) [ServerRequestResponder 3] INFO  com.itko.lisa.coordinator.TestRegistryImpl - added lab member [name:Sim3 (zlis010),ip:<HOSTNAME>,status:Starting] to Default
2021-08-10 16:25:02,908Z (11:25) [Event Sink Thread Pool Thread 1] INFO  com.itko.lisa.coordinator.TestRegistryImpl - Coordinator Servers: 1 Simulator Servers: 2 VSEs: 0 Running vusers: 0 Labs: 1 Memory used 1,760mb, allocated 4,240mb, max 9,102mb (19%) Our cpu usage 0%, system cpu used 0% GC time 0% db ping no connection
2021-08-10 16:25:10,830Z (11:25) [ServerRequestResponder 3] WARN  com.itko.lisa.net.RemoteMethodExec - InvocationTargetException on invoke putSimulator
java.lang.reflect.InvocationTargetException
 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 com.itko.lisa.net.RemoteMethodExec.execute(RemoteMethodExec.java:57)
 at com.itko.lisa.net.ServerRequestHandler.processRMIMessage(ServerRequestHandler.java:533)
 at com.itko.lisa.net.ServerRequestHandler.access$600(ServerRequestHandler.java:70)
 at com.itko.lisa.net.ServerRequestHandler$5.run(ServerRequestHandler.java:451)
 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)
Caused by: java.rmi.RemoteException: JMS Messaging problem with ServerRequestHandler for tcp:/<HOSTNAME>:2014/Sim3 (zlis010) Wire format negotiation timeout: peer did not send his wire format.; nested exception is: 
 com.itko.jms.JMSException: Wire format negotiation timeout: peer did not send his wire format.
 at com.itko.lisa.net.Transporter.init(Transporter.java:412)
 at com.itko.lisa.net.Transporter.<init>(Transporter.java:326)
 at com.itko.lisa.net.Transporter.createTransporter(Transporter.java:285)
 at com.itko.lisa.net.Transporter.getTransporter(Transporter.java:215)
 at com.itko.lisa.net.Transporter.transport(Transporter.java:161)
 at com.itko.lisa.net.Transactor.transact(Transactor.java:68)
 at com.itko.lisa.net.ClientBase.transact(ClientBase.java:359)
 at com.itko.lisa.net.ClientBase.invokeMethod(ClientBase.java:269)
 at com.itko.lisa.net.ClientBase.invokeMethod(ClientBase.java:242)
 at com.itko.lisa.net.SimulatorServerClient.getLisaVersion(SimulatorServerClient.java:54)
 at com.itko.lisa.coordinator.TestRegistryImpl.getComponentBeanEx(TestRegistryImpl.java:1543)
 at com.itko.lisa.coordinator.TestRegistryImpl.putSimulator(TestRegistryImpl.java:1519)
 ... 13 more
Caused by: com.itko.jms.JMSException: Wire format negotiation timeout: peer did not send his wire format.
 at com.itko.activemq.util.JMSExceptionSupport.create(JMSExceptionSupport.java:62)
 at com.itko.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1317)
 at com.itko.activemq.ActiveMQConnection.ensureConnectionInfoSent(ActiveMQConnection.java:1403)
 at com.itko.activemq.ActiveMQConnection.start(ActiveMQConnection.java:523)
 at com.itko.lisa.net.ActiveMQFactory.getRemoteQueueConnection(ActiveMQFactory.java:327)
 at com.itko.lisa.net.Transporter.getOrMakeConnection(Transporter.java:427)
 at com.itko.lisa.net.Transporter.init(Transporter.java:398)
 ... 24 more
Caused by: java.io.IOException: Wire format negotiation timeout: peer did not send his wire format.
 at com.itko.activemq.transport.WireFormatNegotiator.oneway(WireFormatNegotiator.java:98)
 at com.itko.activemq.transport.MutexTransport.oneway(MutexTransport.java:40)
 at com.itko.activemq.transport.ResponseCorrelator.asyncRequest(ResponseCorrelator.java:81)
 at com.itko.activemq.transport.ResponseCorrelator.request(ResponseCorrelator.java:86)
 at com.itko.activemq.ActiveMQConnection.syncSendPacket(ActiveMQConnection.java:1295)
 ... 29 more

Cause

 

when running with AutoSys an environment variable was not being set properly even though AutoSys was set to use the clients Linux environment profile

Environment

 

DevTest 10.6

Component : CA Service Virtualization

Resolution

 
 

I can see when we compare the environments from when running the scripts manually as the user and when AutoSys runs the same scripts, 3 things are missing from the Autosys run that are present in the cmd run.

The environment for the user has a JAVA_HOME, LISA_MORE_VM_PROPS, and a PATH with java in it that are missing when AutoSys runs.
JAVA_HOME=/usr/java64/jdk1.7.0_17
PATH=/usr/java64/jdk1.7.0_17/bin:/bin:/usr/bin:/opt/gnome/bin:/usr/X11/bin
LISA_MORE_VM_PROPS=-Dlisa.tmpdir=/opt/lisavse/tmp

By adding the LISA_MORE_VM_PROPS=-Dlisa.tmpdir=/opt/lisavse/tmp to the Autoscript execution we were able to resolve the issue.