Auto Restart WM Server

WM Forum,

I have faced issue on WM 9.7 Integration server installed on OS Window where as we have trying to identify how WM server was auto or manually restart?

I have attached WM server logs for your reference can some one have a look and let me know if they find any pointer why this server was restarted, Was it due to any other component issue or any manual interaction.

Manual restart : While i have checked in my security logs and didn’t notice any kind of manual restart so trying to identify How come this server got auto restart.

Any hints?

Attach server logs for reference

Integration server shut down and restart was graceful and even i can see all start/stop entries in server logs as well as we never encounter low memory or any kind of db space issue.

Adding to that we don’t have any window scheduled job but have normal window services for software ag integration server where start up type is automatic.

I would be more interested in how and why it restarted. Unless you have some auto-restart code in the batch file (server.bat)(or some job scheduling/monitoring application restarts it) , the IS should not restart itself as describe.

IS is started and monitored by separate process called Tanuki wrapper.
This wrapper is configured to detect whether IS JVM is not responsive (like Loop consuming CPU) or has OOM (Out Of Memory). In such cases the wrapper will restart IS.

To analyze - you can open Global Support ticket.

You can also inspect /profiles/IS_default/logs/wrapper.log for restart initiated by the wrapper.
Look for string “Launching JVM” for IS restart, and preceding lines for the reason.

After analysis - configuration can be done using /profiles/IS-Default/configuration/custom_wrapper.conf…

Regards

Rajiv – As per me, its done manually as I can see there is a difference of 2 minutes b/w shutdown and re-start as per your logs. If it is done by system then we might not have that much time gap. Can you check.

Thanks,

Additional informations from checking the provided log file:

  • Shutdown was incomplete.
  • Shutdown was triggered from console (shutdown.sh) or wrapper.
  • Your installation seems to be incomplete or got damaged somehow as WmDeployer does not load due to missing or inactive WmNUMDeployer package.
  • Check the HTTP-Port as the shutdown sequence mentions a port 9400 which is not opened again after restart.

Regards,
Holger

Good observation Holger :slight_smile:

Rajiv, Please check these options and update your next steps.

Thanks,

I believe as per the logs its some how IS is malfunctioning or not responded with process auto restart by its own and it could also be http port itself not reaching some hiccups as the logs Holger mentioning above for some reason.

Is this happening since after install or can you redo install and configure the Insance IS_Default setting up the custom_wrapper and wrapper config’s as Shmuel suggests?

HTH,
RMG

Hi Shmuel,

I have pulled my WM server OS window wrapper.log can you provide any further pointers which need to analyse?
sure after doing few more analysis will approach sag support team till then gathering reqd info

MR as173d@ If server get restart by system itself will it not take more than 2 mins, how to identify that restart was perform via manual action not by system itself < nothing has capture in security logs>

Holger@

  • Check the HTTP-Port as the shutdown sequence mentions a port 9400 which is not opened again after restart.

I slightly modify my server logs so that by mistake i should not be posting client info in public forum
so by mistake this line got deleted 2015-12-11 07:27:40 CST [ISP.0046.0012I] Enabling HTTP Listener on

Can you pls past line or statement from server log which suggest below your analysis will be helpful in future

  • Shutdown was incomplete.
  • Shutdown was triggered from console (shutdown.sh) or wrapper.

@RMG we are using this server from couple of years and it has been used by business so can’t go for reinstall

Is there any thing i m missing here to look at.

Thanks for all your quick analysis and response.

Hi Rajiv

The wrapper.log is truncated at the top.
As I mentioned - you look for 1) and 2) below

  1. Lines like these with eye catcher “Launching a JVM” - which mean wrapper start the server:

STATUS | wrapper | 2015/12/11 07:23:02 | Base configuration file is D:\webMethods\profiles\IS_XYZ\configuration\wrapper.conf
STATUS | wrapper | 2015/12/11 07:23:02 | Found #include file in D:\webMethods\profiles\IS_XYZ\configuration\wrapper.conf: D:\webMethods\profiles\IS_XYZ/configuration/wrapper-license.conf
STATUS | wrapper | 2015/12/11 07:23:02 | Reading included configuration file, D:\webMethods\profiles\IS_XYZ\configuration\wrapper-license.conf
STATUS | wrapper | 2015/12/11 07:23:02 | Found #include file in D:\webMethods\profiles\IS_XYZ\configuration\wrapper.conf: D:\webMethods\profiles\IS_XYZ/configuration/custom_wrapper.conf
STATUS | wrapper | 2015/12/11 07:23:02 | Reading included configuration file, D:\webMethods\profiles\IS_XYZ\configuration\custom_wrapper.conf
STATUS | wrapper | 2015/12/11 07:23:02 | --> Wrapper Started as Service
STATUS | wrapper | 2015/12/11 07:23:02 | Java Service Wrapper Standard Edition 64-bit 3.5.25
STATUS | wrapper | 2015/12/11 07:23:02 | Copyright © 1999-2014 Tanuki Software, Ltd. All Rights Reserved.
STATUS | wrapper | 2015/12/11 07:23:02 | http://wrapper.tanukisoftware.com
STATUS | wrapper | 2015/12/11 07:23:02 | Licensed to Software AG for Software AG Integration Server
STATUS | wrapper | 2015/12/11 07:23:02 |
STATUS | wrapper | 2015/12/11 07:23:03 | Launching a JVM…
INFO | jvm 1 | 2015/12/11 07:23:09 | WrapperManager: Initializing…

  1. Look at preceding lines why it was closed. Here the file is truncated. Cannot be analyzed.
    In other words, lines before these are missing/truncated:

STATUS | wrapper | 2015/12/11 07:21:52 | Machine is shutting down.
INFO | jvm 1 | 2015/12/11 07:21:53 | Bootstrap: Remote shutdown is disabled.
INFO | jvm 1 | 2015/12/11 07:21:57 | MapiCommunication.destroy() called

Shmuel

Hi,

one reason for incomplete shutdown might be that it took to long and wrapper killed the IS JVM process.
Usually the Common.CDS portion is shutdown at the end of shutdown sequence.

This would also explain the FS Full Data checks (FSData full consistency check is being performed.) in the startup sequence.

Regards,
Holger

Shutdown Sequence:

2015-12-11 07:21:54 CST [ISS.0014.0005I] Shutting down server. JVM Shutdown Hook.
2015-12-11 07:21:54 CST [CommonLib.MWS.0002I] Shutdown Manager running all shutdown hooks.
2015-12-11 07:21:54 CST [ISS.0070.0029I] Stopping listeners from accepting new requests.
2015-12-11 07:21:55 CST [ISS.0134.0068I] JMSTrigger wm.prt.status:BroadcastTrigger has been suspended.
2015-12-11 07:21:55 CST [ISS.0134.0068I] JMSTrigger wm.prt.status:RestartTrigger has been suspended.
2015-12-11 07:21:55 CST [SCC.0126.0201I] SCC ConnectionManager pool XYZ_Support_Utilities.Connections:SuppportUtilitiesConnection stopped
2015-12-11 07:21:56 CST [ISS.0028.0015I] XYZ_Administration: Shutdown service (XYZ_Administration.Startup:stop)
2015-12-11 07:21:56 CST [ISS.0028.0015I] XYZ_XYZ_Adapter_IT2_Src: Shutdown service (XYZ_XYZ_Adapter_IT2_Src.FXTrade.Services.FlowServices:closeSSHConnection)
2015-12-11 07:21:56 CST [SCC.0126.0201I] SCC ConnectionManager pool XYZ_XYZ_Adapter_GL_Tgt.Connections:XYZGlTgtConnection stopped
2015-12-11 07:21:56 CST [SCC.0126.0201I] SCC ConnectionManager pool XYZ_XYZ_Adapter_Tgt.Connections:XYZTgtConnection stopped
2015-12-11 07:21:56 CST [SCC.0126.0201I] SCC ConnectionManager pool XYZ_PIM_Adapter_XYZ_Tgt.Connections:PIMXYZTgtConnection stopped
2015-12-11 07:21:56 CST [SCC.0126.0201I] SCC ConnectionManager pool XYZ_XYZ_Adapter_OracleAR_Tgt.Connections:OracleARTgtConnection stopped
2015-12-11 07:21:56 CST [SCC.0126.0201I] SCC ConnectionManager pool XYZ_Adapter_Connections:XYZCustomLogging stopped
2015-12-11 07:21:56 CST [SCC.0126.0201I] SCC ConnectionManager pool XYZ_AAE_Adapter_XYZ_Tgt.Connections:AAEXYZTgtConnection stopped
2015-12-11 07:21:56 CST [SCC.0126.0201I] SCC ConnectionManager pool XYZ_XYZ_Adapter_Src.Connections:EBIZ stopped
2015-12-11 07:21:56 CST [SCC.0126.0201I] SCC ConnectionManager pool XYZ_OIM_Adapter_OE_Src.Connections:OIMOESrcConnection stopped
2015-12-11 07:21:56 CST [SCC.0126.0201I] SCC ConnectionManager pool XYZ_PIM_Adapter_SSH_Src.Connections:PIMSSHSrcConnection stopped
2015-12-11 07:21:56 CST [SCC.0126.0201I] SCC ConnectionManager pool XYZ_Adapter_Connections:EAIUtilConnection stopped
2015-12-11 07:21:56 CST [SCC.0126.0201I] SCC ConnectionManager pool XYZ_PIM_Adapter_SSH_Tgt.Connections:PIMSSHTgtConnection stopped
2015-12-11 07:21:56 CST [ISS.0028.0015I] WmARTExtDC: Shutdown service (com.wm.artextdc.pkginit:shutdown)
2015-12-11 07:21:56 CST [ISS.0028.0015I] WmJDBCAdapter: Shutdown service (wm.adapter.wmjdbc.admin:unregisterAdapter)
2015-12-11 07:21:56 CST [ART.0114.1107I] Adapter Runtime: Facility 1 - JDBCAdapter removed.
2015-12-11 07:21:56 CST [ISS.0028.0015I] WmSubversion: Shutdown service (wm.server.svn.admin:shutdown)
2015-12-11 07:21:56 CST [ISS.0028.0015I] WmClearCase: Shutdown service (wm.server.cc.admin:shutdown)
2015-12-11 07:21:56 CST [ISS.0028.0015I] WmTomcat: Shutdown service (wm.tomcat.admin:shutdown)
2015-12-11 07:21:56 CST [ISS.0100.0010C] Web Container shutdown completed
2015-12-11 07:21:56 CST [ISS.0028.0015I] WmART: Shutdown service (wm.art.admin:shutdown)
2015-12-11 07:21:56 CST [ISS.0028.0015I] WmVCS: Shutdown service (wm.server.ui:removeSolution)
2015-12-11 07:21:56 CST [ISS.0028.0015I] WmVCS: Shutdown service (wm.server.vcsadmin:shutdown)
2015-12-11 07:21:56 CST [VCS.0132.0051I] VCS package shutting down
2015-12-11 07:21:56 CST [ISS.0028.0015I] WmFlatFile: Shutdown service (wm.server.ff:shutdown)
2015-12-11 07:21:56 CST [ISS.0028.0015I] WmPRT: Shutdown service (wm.prt.admin:shutdown)
2015-12-11 07:21:57 CST [ISP.0046.0011I] Disabling HTTP Listener on port 9400
2015-12-11 07:21:59 CST [ISS.0028.0015I] WmISExtDC: Shutdown service (com.wm.isextdc.PkgInit:shutdown)
2015-12-11 07:21:59 CST [ISS.0028.0015I] WmLogUtil: Shutdown service (wm.loggingUtility:stop)
2015-12-11 07:21:59 CST [ISS.0028.0015I] WmOptimize: Shutdown service (wm.optimize.admin:shutdown)
2015-12-11 07:22:00 CST [ISS.0028.0015I] WmAssetPublisher: Shutdown service (wm.server.metadata.Admin:shutdown)
2015-12-11 07:22:00 CST [ISS.0138.0051I] Asset Publisher package shutting down
2015-12-11 07:22:00 CST [ISS.0028.0015I] WmDesigner: Shutdown service (wm.administrator.repo:centralRepoClose)
2015-12-11 07:22:00 CST [ISS.0028.0015I] WmDesigner: Shutdown service (wm.designer.metadata.AuditLogAccess:shutdown)

Startup-Sequence starts here:


2015-12-11 07:24:15 CST [ISS.0025.0001C] Integration Server 9.7.0.0 Build 361
2015-12-11 07:24:16 CST [ISS.0025.0006I] License Manager started
2015-12-11 07:24:18 CST [ISS.0025.0050W] The JCE Unlimited Strength Jurisdiction Policy File was not found.  Please install it.
2015-12-11 07:24:19 CST [ISS.0025.0041I] FIPS mode not initialized
2015-12-11 07:24:22 CST [BAS.0123.0001I] FSData full consistency check is being performed. Db:WmRepository4\RepoV4
2015-12-11 07:24:24 CST [ISS.0025.0017I] Repository Manager started
2015-12-11 07:24:26 CST [ISS.0025.0024I] JDBC Connection Manager started
2015-12-11 07:24:31 CST [ISS.0095.0013I] Audit Logging initialized.

Usually after a succesful shutdown there are corresponding messages in the server.log which are not present in yours.

Regards,
Holger