Configuring the system for a successful Fusion Application installation – Part 1 – System limits

Introduction

A successful fusion application installation relies on adherence to the guidelines specified in the Installation Guide, the Enterprise Deployment Guide, and the current Release Notes for the release being installed. These documents outline the operating parameters of the environment, under which the fusion application installer would run optimally.  However, differing hardware combinations, including IO and CPU speed can perturb the system sufficiently, resulting in failures during the installation.  This document discusses one such failure due to insufficient resources configured in the system. The discussions herein may also be applied to diagnosing similar failures resulting out of a missed step in configuring the operating system with adequate resources.

This document, therefore, serves the following purposes:

  • Draw attention to the source of the information being the various guides and release notes to get the information needed to configure the environment for a successful install
  • Help troubleshoot the problem and provide the resolution for this particular failure resulting from not adhering to the installation requirements or due to environmental  peculiarities

Main Article

In order to better understand the failure, it is first important to understand the phases the Fusion application installation goes through (once the provisioning framework has been installed and the response file has been created). These are:

Preverify, Install, Pre-Configure, Configure, Configure-Secondary, Post-Configure, Startup, and Validate.

The Post-Configure phase is one of the most resource intensive phases of all the installation phases. This article deals with a specific kind of error that occurs during the Post-Configure phase and provides some insight into the failure, the message to look for, and more importantly the fix that worked for this instance of the failure and some indications as to why.

Failure and Diagnosis

The error in this particular instance occurred during the start up of the financial domain. The log provided has some secondary failures perhaps due to cascading errors from the core issue. Specifically, the error message about the java heap size, the large number that looks like an overflow error, and the recommendation in the log that indicates it might be a memory issue, were in fact misleading.  The root cause was not a memory issue at all.  The log associated with this secondary error is provided below

Java heap 1G reserved, 128M committed
Paged memory=18014398506928488K/119198660K.
Your Java heap size might be set too high.
Try to reduce the Java heap size using -Xmx:<size> (e.g. “-Xmx12
[INFO ][memory ][Thu Apr  5 22:08:51 2012][1333678131826][20696] Dumped heap as hprof data to /a01/app/oracle/product/instance/debug/jrockit_20696.hprof
java.lang.OutOfMemoryError: Resource temporarily unavailable in tsStartJavaThread (lifecycle.c:1096).
Java heap 1G reserved, 128M committed
Paged memory=18014398506928488K/119198660K.
Your Java heap size might be set too high.
Try to reduce the Java heap size using -Xmx:<size> (e.g. “-Xmx128m”).
You can also try to free low memory by disabling
compressed references, -XXcompressedRefs=false.
at java/lang/Thread.start0()V(Native Method)
at java/lang/Thread.start(Thread.java:640)

 

The actual error was this nondescript message

[ERROR][thread ][Thu Apr  5 22:08:50 2012][1333678130777][20696] Could not start thread JPS FileChangeNotifier<clean-only>. Resource temporarily unavailable

This pointed at a resource limit issue and from prior experience it was clear this issue was associated with the shell parameters set via ulimits (or the system limits configuration file) – specifically the nproc and nfiles.

Changing the limits to the following values based also proved unsuccessful:

*           soft    nproc           4000
*           hard    nproc           65535
oracle      soft    nofile          131072
oracle      hard    nofile          327679

Success was finally achieved with the below values:

*           soft    nproc           65535
*           hard    nproc           65535
oracle      soft    nofile          400000
oracle      hard    nofile          400000

Analysis and Hypothesis

Invariably, the question comes as to why the conventional values, and in actuality values much greater than normal during the couple of failed attempts, did not work?  After a bit of investigation it was hypothesized that the resources were being consumed differently on the server in question.  The server was running a processor which was slower than other machines on which installations with lower values had succeeded.  In fact, it was slower by almost 50%. Thus, the slower processing also resulted in processes staying alive longer, elongating the time with which the file handles are held are process slots are consumed.  The result was exhaustion of system resources which prevented subsequent processes from starting up and failing the installation.

Summary

When encountering what appears to be an out of memory error — keep in mind it may not be memory at all.  Carefully review the out of error message, checking for any sign of this being caused by ulimits being set too low.

APPENDIX A – The Log

java version “1.6.0_24”
Java(TM) SE Runtime Environment (build 1.6.0_24-b07)
Oracle JRockit(R) (build R28.1.3-11-141760-1.6.0_24-20110301-1432-linux-x86_64, compiled mode)

[INFO ][memory ][Thu Apr  5 22:08:25 2012][1333678105751][20696] [YC#2] 6.382-6.434: YC 93713KB->48472KB (131072KB), 0.051 s, sum of pauses 51.176 ms, longest pause 51.176 ms.
<Apr 5, 2012 10:08:27 PM EDT> <Notice> <WebLogicServer> <BEA-000365> <Server state changed to STARTING>
<Apr 5, 2012 10:08:27 PM EDT> <Info> <WorkManager> <BEA-002900> <Initializing self-tuning thread pool>
[INFO ][memory ][Thu Apr  5 22:08:28 2012][1333678108046][20696] [YC#3] 8.689-8.728: YC 104949KB->63325KB (131072KB), 0.040 s, sum of pauses 39.579 ms, longest pause 39.579 ms.
[INFO ][memory ][Thu Apr  5 22:08:30 2012][1333678110200][20696] [YC#4] 10.852-10.882: YC 115625KB->70439KB (131072KB), 0.030 s, sum of pauses 29.955 ms, longest pause 29.955 ms.
[INFO ][memory ][Thu Apr  5 22:08:31 2012][1333678111226][20696] [OC#1] 11.851-11.909: OC 118208KB->23858KB (131072KB), 0.058 s, sum of pauses 46.435 ms, longest pause 46.435 ms.
[INFO ][memory ][Thu Apr  5 22:08:34 2012][1333678114847][20696] [YC#5] 15.505-15.529: YC 94092KB->45958KB (131072KB), 0.024 s, sum of pauses 23.928 ms, longest pause 23.928 ms.
Apr 5, 2012 10:08:38 PM oracle.security.jps.az.internal.common.scanner.PolicyChangeScannerThread run
INFO: Policy store cleanup thread started.
[INFO ][memory ][Thu Apr  5 22:08:39 2012][1333678119771][20696] [YC#6] 20.422-20.454: YC 104072KB->58412KB (131072KB), 0.031 s, sum of pauses 30.896 ms, longest pause 30.896 ms.
[INFO ][memory ][Thu Apr  5 22:08:47 2012][1333678127833][20696] [YC#7] 28.476-28.515: YC 108549KB->61804KB (131072KB), 0.039 s, sum of pauses 39.123 ms, longest pause 39.123 ms.
[ERROR][thread ][Thu Apr  5 22:08:50 2012][1333678130777][20696] Could not start thread JPS FileChangeNotifier<clean-only>. Resource temporarily unavailable
[ERROR][memory ][Thu Apr  5 22:08:50 2012][1333678130777][20696] Throwing OutOfMemory: Resource temporarily unavailable in tsStartJavaThread (lifecycle.c:1096).
Java heap 1G reserved, 128M committed
Paged memory=18014398506928488K/119198660K.
Your Java heap size might be set too high.
Try to reduce the Java heap size using -Xmx:<size> (e.g. “-Xmx12
[INFO ][memory ][Thu Apr  5 22:08:51 2012][1333678131826][20696] Dumped heap as hprof data to /a01/app/oracle/product/instance/debug/jrockit_20696.hprof
java.lang.OutOfMemoryError: Resource temporarily unavailable in tsStartJavaThread (lifecycle.c:1096).
Java heap 1G reserved, 128M committed
Paged memory=18014398506928488K/119198660K.
Your Java heap size might be set too high.
Try to reduce the Java heap size using -Xmx:<size> (e.g. “-Xmx128m”).
You can also try to free low memory by disabling
compressed references, -XXcompressedRefs=false.
at java/lang/Thread.start0()V(Native Method)
at java/lang/Thread.start(Thread.java:640)
at java/util/concurrent/ThreadPoolExecutor.addIfUnderCorePoolSize(ThreadPoolExecutor.java:703)
at java/util/concurrent/ThreadPoolExecutor.prestartCoreThread(ThreadPoolExecutor.java:1381)
at java/util/concurrent/ScheduledThreadPoolExecutor.delayedExecute(ScheduledThreadPoolExecutor.java:222)
at java/util/concurrent/ScheduledThreadPoolExecutor.scheduleWithFixedDelay(ScheduledThreadPoolExecutor.java:443)
at java/util/concurrent/Executors$DelegatedScheduledExecutorService.scheduleWithFixedDelay(Executors.java:660)
at oracle/security/jps/internal/common/notification/filesystem/FileChangeNotifier.schedule(FileChangeNotifier.java:255)
at oracle/security/jps/internal/common/util/JpsCommonUtil.initDocumentChangeNotifier(JpsCommonUtil.java:1105)
at oracle/security/jps/wls/JpsWlsStartupClass.main(JpsWlsStartupClass.java:47)
at jrockit/vm/RNI.c2java(JJJJJ)V(Native Method)
at jrockit/vm/Reflect.invokeMethod(Ljava/lang/Object;Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;(Native Method)
at sun/reflect/NativeMethodAccessorImpl.invoke0(Ljava/lang/reflect/Method;Ljava/lang/Object;[Ljava/lang/Object;)Ljava/lang/Object;(Native Method)
at sun/reflect/NativeMethodAccessorImpl.invoke(NativeMethodAccessorImpl.java:39)
at sun/reflect/DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)
at java/lang/reflect/Method.invoke(Method.java:597)
at weblogic/management/deploy/classdeployment/ClassDeploymentManager.invokeMain(ClassDeploymentManager.java:362)
at weblogic/management/deploy/classdeployment/ClassDeploymentManager.invokeClass(ClassDeploymentManager.java:272)
at weblogic/management/deploy/classdeployment/ClassDeploymentManager.access$000(ClassDeploymentManager.java:54)
at weblogic/management/deploy/classdeployment/ClassDeploymentManager$1.run(ClassDeploymentManager.java:214)
at weblogic/security/acl/internal/AuthenticatedSubject.doAs(AuthenticatedSubject.java:321)
at weblogic/security/service/SecurityManager.runAs(SecurityManager.java:120)
at weblogic/management/deploy/classdeployment/ClassDeploymentManager.invokeClassDeployment(ClassDeploymentManager.java:207)
at weblogic/management/deploy/classdeployment/ClassDeploymentManager.runStartupsBeforeAppDeployments(ClassDeploymentManager.java:149)
at weblogic/management/deploy/classdeployment/ClassDeploymentService.start(ClassDeploymentService.java:20)
at weblogic/t3/srvr/SubsystemRequest.run(SubsystemRequest.java:64)
at weblogic/work/ExecuteThread.execute(ExecuteThread.java:209)
at weblogic/work/ExecuteThread.run(ExecuteThread.java:178)
at jrockit/vm/RNI.c2java(JJJJJ)V(Native Method)
— end of trace
[ERROR] Exit on OutOfMemory requested. Exiting.
JRockit aborted: Exit requested on OOM (51)
<Apr 5, 2012 10:08:51 PM> <FINEST> <NodeManager> <Waiting for the process to die: 20354>
<Apr 5, 2012 10:08:51 PM> <INFO> <NodeManager> <Server failed during startup so will not be restarted>
<Apr 5, 2012 10:08:51 PM> <FINEST> <NodeManager> <runMonitor returned, setting finished=true and notifying waiters>

Add Your Comment