The dev_cog server got hung because of 100% CPU usage by 2 java.exe processes.

[tejas]

Introduction:
   Hello everyone, my name is tejas zode and working as cognos DBA. I have successfully resolved the low performance issue of cognos development server.
Issue:
   The development server got hung because of 100% CPU usage by 2 java.exe processes.
Memory used:  8 Gig
CPU usage: 100%
Diagnosis:
1.I trace the java.exe and found that the process running under java.exe is not provided the proper permission; hence they are not having desired access. I used procmon tool of Microsoft for this purpose.
Output:
D:\Program Files\ibm\cognos\c10_64\bin64\CAM_LPSvr.exe>
"<D:\Program Files\ibm\cognos\c10_64\bin64\CAM_LPSvr.exe>" camssl=false cam=true idleTimeLimitSec=600 "COG_ROOT=D:/Program Files/ibm/cognos/c10_64" threads=32 cclthreadstacksize=1048576

<D:\Program Files\ibm\cognos\c10_64\bin\BIBusTKServerMain.exe>
"<D:\Program Files\ibm\cognos\c10_64\bin\BIBusTKServerMain.exe>" threads=20 camssl=false "COG_ROOT=D:/Program Files/ibm/cognos/c10_64" cam=true idleTimeLimitSec=900 lightThreadStackSize=327680 lightthreads=10

<D:\Program Files\ibm\cognos\c10_64\bin\BmtMDProviderMain.exe>
"<D:\Program Files\ibm\cognos\c10_64\bin\BmtMDProviderMain.exe>" threads=10 camssl=false "COG_ROOT=D:/Program Files/ibm/cognos/c10_64" cam=true idleTimeLimitSec=900


2.   I have checked the logs related to java and tomcat in the file named as catalina. It consist of following java exceptions.
Apr 15, 2014 4:55:52 AM org.apache.catalina.loader.WebappClassLoader findResourceInternal
INFO: Illegal access: this web application instance has been stopped already.  Could not load jcam_errors_en_US.properties.  The eventual following stack trace is caused by an error thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access, and has no functional impact.
Apr 15, 2014 4:55:52 AM ClientCommunicatorAdmin restart
WARNING: Failed to restart: java.io.IOException: Failed to get a RMI stub: javax.naming.CommunicationException [Root exception is java.rmi.ConnectIOException: Exception creating connection to: c3b1devcogac1; nested exception is:
   java.io.IOException:  Reason: java.net.ConnectException: Connection refused: connect]
Apr 15, 2014 4:55:52 AM org.apache.catalina.loader.WebappClassLoader loadClass
INFO: Illegal access: this web application instance has been stopped already.  Could not load javax.management.remote.rmi.RMIConnector.  The eventual following stack trace is caused by an error thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access, and has no functional impact.
java.lang.IllegalStateException
   at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1566)
   at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1526)
   at com.cognos.pogo.isolation.ParanoidClassLoader.findClassParentLast(ParanoidClassLoader.java:149)
   at com.cognos.pogo.isolation.ParanoidClassLoader.loadClass(ParanoidClassLoader.java:133)
   at java.lang.ClassLoader.loadClass(ClassLoader.java:690)
   at com.cognos.xqe.management.XqeSystemMetricsProxyCreator.handleNotification(XqeSystemMetricsProxyCreator.java:268)
   at javax.management.NotificationBroadcasterSupport.handleNotification(NotificationBroadcasterSupport.java:285)
   at javax.management.NotificationBroadcasterSupport$SendNotifJob.run(NotificationBroadcasterSupport.java:350)
   at javax.management.NotificationBroadcasterSupport$1.execute(NotificationBroadcasterSupport.java:335)
   at javax.management.NotificationBroadcasterSupport.sendNotification(NotificationBroadcasterSupport.java:258)
   at javax.management.remote.rmi.RMIConnector.sendNotification(RMIConnector.java:447)
   at javax.management.remote.rmi.RMIConnector.close(RMIConnector.java:539)
   at javax.management.remote.rmi.RMIConnector.close(RMIConnector.java:451)
   at javax.management.remote.rmi.RMIConnector$RMIClientCommunicatorAdmin.doStop(RMIConnector.java:1662)
   at com.sun.jmx.remote.internal.ClientCommunicatorAdmin.restart(ClientCommunicatorAdmin.java:165)
   at com.sun.jmx.remote.internal.ClientCommunicatorAdmin.gotIOException(ClientCommunicatorAdmin.java:66)
   at javax.management.remote.rmi.RMIConnector$RMIClientCommunicatorAdmin.gotIOException(RMIConnector.java:1480)
   at javax.management.remote.rmi.RMIConnector$RMINotifClient.fetchNotifs(RMIConnector.java:1356)
   at com.sun.jmx.remote.internal.ClientNotifForwarder$NotifFetcher.fetchNotifs(ClientNotifForwarder.java:599)
   at com.sun.jmx.remote.internal.ClientNotifForwarder$NotifFetcher.doRun(ClientNotifForwarder.java:482)
   at com.sun.jmx.remote.internal.ClientNotifForwarder$NotifFetcher.run(ClientNotifForwarder.java:463)
   at com.sun.jmx.remote.internal.ClientNotifForwarder$LinearExecutor$1.run(ClientNotifForwarder.java:119)

Apr 15, 2014 4:55:52 AM RMIConnector RMIClientCommunicatorAdmin-doStop
WARNING: Failed to call the method close():java.rmi.ConnectIOException: error during JRMP connection establishment; nested exception is:
   java.net.SocketException: Connection reset
Apr 15, 2014 4:55:55 AM org.apache.catalina.loader.WebappClassLoader loadClass
INFO: Illegal access: this web application instance has been stopped already.  Could not load DispatcherMessages.  The eventual following stack trace is caused by an error thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access, and has no functional impact.
java.lang.IllegalStateException
   at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1566)
   at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1526)
   at com.cognos.pogo.isolation.ParanoidClassLoader.findClassParentLast(ParanoidClassLoader.java:149)
   at com.cognos.pogo.isolation.ParanoidClassLoader.loadClass(ParanoidClassLoader.java:133)
   at java.lang.ClassLoader.loadClass(ClassLoader.java:690)
   at java.util.ResourceBundle$Control.newBundle(ResourceBundle.java:2576)
   at java.util.ResourceBundle.loadBundle(ResourceBundle.java:1447)
   at java.util.ResourceBundle.findBundle(ResourceBundle.java:1411)
   at java.util.ResourceBundle.findBundle(ResourceBundle.java:1365)
   at java.util.ResourceBundle.getBundleImpl(ResourceBundle.java:1307)
   at java.util.ResourceBundle.getBundle(ResourceBundle.java:807)
   at com.cognos.pogo.impl.DispatcherStringsImpl.getResourceBundleString(DispatcherStringsImpl.java:104)
   at com.cognos.pogo.impl.DispatcherStringsImpl.getStringFromBundle(DispatcherStringsImpl.java:99)
   at com.cognos.pogo.impl.DispatcherStringsImpl.getString(DispatcherStringsImpl.java:110)
   at com.cognos.pogo.impl.DispatcherStrings.getString(DispatcherStrings.java:38)
   at com.cognos.pogo.contentmanager.coordinator.ActiveCMControl.sendElectCommand(ActiveCMControl.java:216)
   at com.cognos.pogo.contentmanager.coordinator.ActiveCMControl.startTimer(ActiveCMControl.java:166)
   at com.cognos.pogo.contentmanager.coordinator.ActiveCMControl.cMIOErrorNotify(ActiveCMControl.java:95)
   at com.cognos.pogo.contentmanager.coordinator.ActiveCMChecker.notifyFailure(ActiveCMChecker.java:134)
   at com.cognos.pogo.contentmanager.coordinator.ActiveCMChecker.checkCM(ActiveCMChecker.java:114)
   at com.cognos.pogo.contentmanager.coordinator.ActiveCMChecker.access$000(ActiveCMChecker.java:28)
   at com.cognos.pogo.contentmanager.coordinator.ActiveCMChecker$CMCheckTask.safeRun(ActiveCMChecker.java:144)
   at com.cognos.pogo.util.threads.SafeTimerTask.run(SafeTimerTask.java:42)
   at java.util.TimerThread.mainLoop(Timer.java:566)
   at java.util.TimerThread.run(Timer.java:516)

Apr 15, 2014 4:55:55 AM org.apache.catalina.loader.WebappClassLoader loadClass
INFO: Illegal access: this web application instance has been stopped already.  Could not load DispatcherMessages_en.  The eventual following stack trace is caused by an error thrown for debugging purposes as well as to attempt to terminate the thread which caused the illegal access, and has no functional impact.
java.lang.IllegalStateException
   at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1566)
   at org.apache.catalina.loader.WebappClassLoader.loadClass(WebappClassLoader.java:1526)
   at com.cognos.pogo.isolation.ParanoidClassLoader.findClassParentLast(ParanoidClassLoader.java:149)
   at com.cognos.pogo.isolation.ParanoidClassLoader.loadClass(ParanoidClassLoader.java:133)
   at java.lang.ClassLoader.loadClass(ClassLoader.java:690)
   at java.util.ResourceBundle$Control.newBundle(ResourceBundle.java:2576)
   at java.util.ResourceBundle.loadBundle(ResourceBundle.java:1447)
   at java.util.ResourceBundle.findBundle(ResourceBundle.java:1411)
   at java.util.ResourceBundle.getBundleImpl(ResourceBundle.java:1307)
   at java.util.ResourceBundle.getBundle(ResourceBundle.java:807)
   at com.cognos.pogo.impl.DispatcherStringsImpl.getResourceBundleString(DispatcherStringsImpl.java:104)
   at com.cognos.pogo.impl.DispatcherStringsImpl.getStringFromBundle(DispatcherStringsImpl.java:99)
   at com.cognos.pogo.impl.DispatcherStringsImpl.getString(DispatcherStringsImpl.java:110)
   at com.cognos.pogo.impl.DispatcherStrings.getString(DispatcherStrings.java:38)
   at com.cognos.pogo.contentmanager.coordinator.ActiveCMControl.sendElectCommand(ActiveCMControl.java:216)
   at com.cognos.pogo.contentmanager.coordinator.ActiveCMControl.startTimer(ActiveCMControl.java:166)
   at com.cognos.pogo.contentmanager.coordinator.ActiveCMControl.cMIOErrorNotify(ActiveCMControl.java:95)
   at com.cognos.pogo.contentmanager.coordinator.ActiveCMChecker.notifyFailure(ActiveCMChecker.java:134)
   at com.cognos.pogo.contentmanager.coordinator.ActiveCMChecker.checkCM(ActiveCMChecker.java:114)
   at com.cognos.pogo.contentmanager.coordinator.ActiveCMChecker.access$000(ActiveCMChecker.java:28)
   at com.cognos.pogo.contentmanager.coordinator.ActiveCMChecker$CMCheckTask.safeRun(ActiveCMChecker.java:144)
   at com.cognos.pogo.util.threads.SafeTimerTask.run(SafeTimerTask.java:42)
   at java.util.TimerThread.mainLoop(Timer.java:566)
   at java.util.TimerThread.run(Timer.java:516)

Solution:
   Restrict both the java process to use memory by making change in IBM cognos  configuration.
Path: IBM cognos configuration > Environment > IBM cognos services > IBM cognos
   In the resource properties I have changed Maximum memory for tomcat in MA from 1536 to 768.   
Result:
CPU usage : 0%
Memory usage: 4Gig
   After allpying this solution I have rechecked the logs and I have not found any exception of java.
The output of my log file after this looks like:
   Apr 15, 2014 5:45:40 AM org.apache.catalina.core.AprLifecycleListener init
INFO: The APR based Apache Tomcat Native library which allows optimal performance in production environments was not found on the java.library.path: D:\Program Files\ibm\cognos\c10_64\bin64\jre\7.0\bin\compressedrefs;D:\Program Files\ibm\cognos\c10_64\bin64\jre\7.0\bin;C:\Windows\system32;C:\Windows;D:\ProgramFiles\ibm\cognos\vvm\apps\informix\bin;D:\Program Files (x86)\IBM\Informix\11.70\bin;C:\Program Files (x86)\IBM\Informix\11.70\bin;D:\Program Files\ibm\cognos\vvm\bin;C:\Windows\SysWOW64;C:\Program Files (x86)\ibm\gsk8\lib;C:\Program Files (x86)\ibm\gsk8\bin;C:\Windows\system32;C:\Windows;C:\Windows\System32\Wbem;C:\Windows\System32\WindowsPowerShell\v1.0\;.
Apr 15, 2014 5:45:40 AM org.apache.coyote.http11.Http11Protocol init
INFO: Initializing Coyote HTTP/1.1 on http-9300
Apr 15, 2014 5:45:40 AM org.apache.catalina.startup.Catalina load
INFO: Initialization processed in 444 ms
Apr 15, 2014 5:45:40 AM org.apache.catalina.core.StandardService start
INFO: Starting service Catalina
Apr 15, 2014 5:45:40 AM org.apache.catalina.core.StandardEngine start
INFO: Starting Servlet Engine: Apache Tomcat/6.0.35
Apr 15, 2014 5:45:45 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory Audit
Apr 15, 2014 5:45:45 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory samples
Apr 15, 2014 5:45:46 AM org.apache.catalina.startup.HostConfig deployDirectory
INFO: Deploying web application directory utilities
Apr 15, 2014 5:45:46 AM org.apache.coyote.http11.Http11Protocol start
INFO: Starting Coyote HTTP/1.1 on http-9300
Apr 15, 2014 5:45:46 AM org.apache.catalina.startup.Catalina start
INFO: Server startup in 5804 ms