This discussion is archived
4 Replies Latest reply: Sep 19, 2013 4:46 AM by user10132385 RSS

Frequent FR Server Crashes

866532 Newbie
866532 Sep 16, 2013 11:21 AM
Currently Being Moderated

Hello All,

We have a load balanced environment. This month being a busy time, we are experiencing frequent FR Server crashes. FR server1 is crashing more frequently than FR server2.

Our env:

Windows 2008 R2 64 bit

Hyperion 11.1.2.1.127

Heap size -> min : 1024  & max : 2048

 

 

readme.txt for Incident report on server2

Incident Id: 7831

Incident Source: SYSTEM

Create Time: Mon Sep 16 13:26:56 EDT 2013

Problem Key: OFM-99999 [FinancialReporting1][oracle.EPMRAF.com.brio.one.services.utils.css.CSSAccess]

Application Name: FINANCIALREPORTING

Error Message Id: OFM-99999

 

Description

-----------

 

The following log message matched one or more log detection conditions:

 

[2013-09-16T13:26:56.495-04:00] [FinancialReporting1] [INCIDENT_ERROR] [] [oracle.EPMRAF.com.brio.one.services.utils.css.CSSAccess] [host: HYP11WEB02] [nwaddr: 172.19.13.103] [tid: 95] [userId: <anonymous>] [ecid: 0000K4bEB296YNL6yRmZMG1IDlYu000001,1:22536] [APP: FINANCIALREPORTING#11.1.2.0] Error retrieving SAP login ticket[[

EPMCSS-00000: Failed to process request. Internal server error. Refer EPM Shared Services Security log file for related errors.

    at com.hyperion.css.validate.Validator.validateToken(Validator.java:657)

    at com.hyperion.css.CSSSystem.getSAPTicket(CSSSystem.java:431)

    at com.brio.one.services.utils.css.CSSAccess.getSAPTicket(Unknown Source)

    at com.brio.one.client.proxy.SessionProxy.getSAPTicket(Unknown Source)

    at com.brio.one.client.proxy.SessionProxy.getSAPTicket(Unknown Source)

    at com.hyperion.reporting.jsr283.foundation.FoundationSession.init(FoundationSession.java:139)

    at com.hyperion.reporting.jsr283.foundation.FoundationSession.<init>(FoundationSession.java:123)

    at com.hyperion.reporting.jsr283.foundation.FoundationRepository.joinSession(FoundationRepository.java:209)

    at com.hyperion.reporting.jsr283.foundation.FoundationRepository.login(FoundationRepository.java:90)

    at com.hyperion.reporting.jsr283.foundation.FoundationRepository.login(FoundationRepository.java:107)

    at com.hyperion.reporting.security.impl.HsSecurityHelper.login(Unknown Source)

    at com.hyperion.reporting.security.impl.HsSecurityHelper.authenticateUser(Unknown Source)

    at com.hyperion.reporting.hsserver.impl.HsServer.openSession(Unknown Source)

    at sun.reflect.GeneratedMethodAccessor3519.invoke(Unknown Source)

    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

    at java.lang.reflect.Method.invoke(Method.java:597)

    at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:305)

    at sun.rmi.transport.Transport$1.run(Transport.java:160)

    at sun.rmi.transport.Transport.serviceCall(Transport.java:155)

    at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:535)

    at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:790)

    at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649)

    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)

    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:909)

    at java.lang.Thread.run(Thread.java:619)

 

]]

 

Stack Trace

-----------

EPMCSS-00000: Failed to process request. Internal server error. Refer EPM Shared Services Security log file for related errors.

    at com.hyperion.css.validate.Validator.validateToken(Validator.java:657)

    at com.hyperion.css.CSSSystem.getSAPTicket(CSSSystem.java:431)

    at com.brio.one.services.utils.css.CSSAccess.getSAPTicket(Unknown Source)

    at com.brio.one.client.proxy.SessionProxy.getSAPTicket(Unknown Source)

    at com.brio.one.client.proxy.SessionProxy.getSAPTicket(Unknown Source)

    at com.hyperion.reporting.jsr283.foundation.FoundationSession.init(FoundationSession.java:139)

    at com.hyperion.reporting.jsr283.foundation.FoundationSession.<init>(FoundationSession.java:123)

    at com.hyperion.reporting.jsr283.foundation.FoundationRepository.joinSession(FoundationRepository.java:209)

    at com.hyperion.reporting.jsr283.foundation.FoundationRepository.login(FoundationRepository.java:90)

    at com.hyperion.reporting.jsr283.foundation.FoundationRepository.login(FoundationRepository.java:107)

    at com.hyperion.reporting.security.impl.HsSecurityHelper.login(Unknown Source)

    at com.hyperion.reporting.security.impl.HsSecurityHelper.authenticateUser(Unknown Source)

    at com.hyperion.reporting.hsserver.impl.HsServer.openSession(Unknown Source)

    at sun.reflect.GeneratedMethodAccessor3519.invoke(Unknown Source)

    at sun.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:25)

    at java.lang.reflect.Method.invoke(Method.java:597)

    at sun.rmi.server.UnicastServerRef.dispatch(UnicastServerRef.java:305)

    at sun.rmi.transport.Transport$1.run(Transport.java:160)

    at sun.rmi.transport.Transport.serviceCall(Transport.java:155)

    at sun.rmi.transport.tcp.TCPTransport.handleMessages(TCPTransport.java:535)

    at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run0(TCPTransport.java:790)

    at sun.rmi.transport.tcp.TCPTransport$ConnectionHandler.run(TCPTransport.java:649)

    at java.util.concurrent.ThreadPoolExecutor$Worker.runTask(ThreadPoolExecutor.java:886)

    at java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:909)

    at java.lang.Thread.run(Thread.java:619)

 

Diagnostic Dumps

----------------

 

Name: dms.ecidctx

Dump Files: dms_ecidctx107_i7831.dmp

 

Name: jvm.threads

Dump Files: jvm_threads108_i7831.dmp

 

Name: dms.metrics

Dump Files: dms_metrics109_i7831.dmp

 

Name: odl.quicktrace

Dump Files: odl_quicktrace110_i7831.dmp

 

Name: odl.logs

Dump Arguments: ecid=0000K4bEB296YNL6yRmZMG1IDlYu000001

Dump Files: odl_logs111_i7831.dmp

 

Name: odl.logs

Dump Arguments: timestamp=1379352416495

Dump Files: odl_logs112_i7831.dmp

 

Name: wls.image

Dump Files: wls_image113_i7831.zip

2

  • 1. Re: Frequent FR Server Crashes
    866532 Newbie
    866532 Sep 16, 2013 11:31 AM (in response to 866532)
    Currently Being Moderated

    Logs before crash on server1. The FR service stopped at 12:10pm

    FinancialReporting0.log

    ####<Sep 16, 2013 11:11:47 AM EDT> <Notice> <WebLogicServer> <HYP11WEB01> <FinancialReporting0> <Main Thread> <<WLS Kernel>> <> <> <1379344307951> <BEA-000360> <Server started in RUNNING mode>

    ####<Sep 16, 2013 11:11:47 AM EDT> <Info> <J2EE> <HYP11WEB01> <FinancialReporting0> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1379344307955> <BEA-160151> <Registered library Extension-Name: bea_wls_async_response (JAR).>

    ####<Sep 16, 2013 11:11:55 AM EDT> <Info> <Cluster> <HYP11WEB01> <FinancialReporting0> <[STANDBY] ExecuteThread: '5' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1379344315666> <BEA-000128> <Updating -8635502875397306417S:172.19.13.103:[8200,8200,-1,-1,-1,-1,-1]:EPMSystem:FinancialReporting1 in the cluster.>

    ####<Sep 16, 2013 11:12:15 AM EDT> <Info> <ServletContext-/hr> <HYP11WEB01> <FinancialReporting0> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <0000K4bL49K6YNL6yRnZ6G1IDlyT000001> <1379344335532> <BEA-000000> <JspServlet: param verbose initialized to: true>

    ####<Sep 16, 2013 11:12:15 AM EDT> <Info> <ServletContext-/hr> <HYP11WEB01> <FinancialReporting0> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <0000K4bL49K6YNL6yRnZ6G1IDlyT000001> <1379344335532> <BEA-000000> <JspServlet: param packagePrefix initialized to: jsp_servlet>

    ####<Sep 16, 2013 11:12:15 AM EDT> <Info> <ServletContext-/hr> <HYP11WEB01> <FinancialReporting0> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <0000K4bL49K6YNL6yRnZ6G1IDlyT000001> <1379344335532> <BEA-000000> <JspServlet: param compilerclass initialized to: null>

    ####<Sep 16, 2013 11:12:15 AM EDT> <Info> <ServletContext-/hr> <HYP11WEB01> <FinancialReporting0> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <0000K4bL49K6YNL6yRnZ6G1IDlyT000001> <1379344335533> <BEA-000000> <JspServlet: param compileCommand initialized to: javac>

    ####<Sep 16, 2013 11:12:15 AM EDT> <Info> <ServletContext-/hr> <HYP11WEB01> <FinancialReporting0> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <0000K4bL49K6YNL6yRnZ6G1IDlyT000001> <1379344335533> <BEA-000000> <JspServlet: param compilerval initialized to: javac>

    ####<Sep 16, 2013 11:12:15 AM EDT> <Info> <ServletContext-/hr> <HYP11WEB01> <FinancialReporting0> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <0000K4bL49K6YNL6yRnZ6G1IDlyT000001> <1379344335533> <BEA-000000> <JspServlet: param pageCheckSeconds initialized to: -1>

    ####<Sep 16, 2013 11:12:15 AM EDT> <Info> <ServletContext-/hr> <HYP11WEB01> <FinancialReporting0> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <0000K4bL49K6YNL6yRnZ6G1IDlyT000001> <1379344335533> <BEA-000000> <JspServlet: param encoding initialized to: null>

    ####<Sep 16, 2013 11:12:15 AM EDT> <Info> <ServletContext-/hr> <HYP11WEB01> <FinancialReporting0> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <0000K4bL49K6YNL6yRnZ6G1IDlyT000001> <1379344335533> <BEA-000000> <JspServlet: param superclass initialized to null>

    ####<Sep 16, 2013 11:12:15 AM EDT> <Info> <ServletContext-/hr> <HYP11WEB01> <FinancialReporting0> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <0000K4bL49K6YNL6yRnZ6G1IDlyT000001> <1379344335534> <BEA-000000> <JspServlet: param workingDir initialized to: D:\Oracle\Middleware\user_projects\domains\EPMSystem\precompiled\hr>

    ####<Sep 16, 2013 11:12:15 AM EDT> <Info> <ServletContext-/hr> <HYP11WEB01> <FinancialReporting0> <[ACTIVE] ExecuteThread: '0' for queue: 'weblogic.kernel.Default (self-tuning)'> <<anonymous>> <> <0000K4bL49K6YNL6yRnZ6G1IDlyT000001> <1379344335535> <BEA-000000> <JspServlet: initialization complete>

    ####<Sep 16, 2013 11:12:45 AM EDT> <Info> <Common> <HYP11WEB01> <FinancialReporting0> <Thread-51> <<anonymous>> <> <0000K4bKs0z6YNL6yRnZ6G1IDlyT000000> <1379344365081> <BEA-000628> <Created "1" resources for pool "raframework_datasource", out of which "1" are available and "0" are unavailable.>

    ####<Sep 16, 2013 11:26:28 AM EDT> <Info> <JDBC> <HYP11WEB01> <FinancialReporting0> <[ACTIVE] ExecuteThread: '1' for queue: 'weblogic.kernel.Default (self-tuning)'> <<WLS Kernel>> <> <> <1379345188061> <BEA-001128> <Connection for pool "raframework_datasource" closed.>

     

    FRLogging.log

    [2013-09-16T12:07:12.975-04:00] [FinancialReporting0] [ERROR] [00063] [oracle.EPMFR.core] [tid: Thread-37] [userId: <anonymous>] [ecid: 0000K4bKs0z6YNL6yRnZ6G1IDlyT000000,1:29968] [SRC_CLASS: com.hyperion.reporting.contents.GridResult] [APP: FINANCIALREPORTING#11.1.2.0] [SRC_METHOD: logUnevaluatedCells] The maximum calculation limit of 5 has been reached. Further processing of this cell calculation will not occur

    [2013-09-16T12:07:12.975-04:00] [FinancialReporting0] [NOTIFICATION] [] [oracle.EPMFR.performance] [tid: Thread-37] [userId: <anonymous>] [ecid: 0000K4bKs0z6YNL6yRnZ6G1IDlyT000000,1:29968] [SRC_CLASS: com.hyperion.reporting.util.HRLogTimer] [APP: FINANCIALREPORTING#11.1.2.0] [SRC_METHOD: logTimeEnd] PERF: 000041: 0000000000    GridResult                                  evaluateCalcCells: pass 0   

    [2013-09-16T12:07:12.976-04:00] [FinancialReporting0] [NOTIFICATION] [] [oracle.EPMFR.performance] [tid: Thread-37] [userId: <anonymous>] [ecid: 0000K4bKs0z6YNL6yRnZ6G1IDlyT000000,1:29968] [SRC_CLASS: com.hyperion.reporting.util.HRLogTimer] [APP: FINANCIALREPORTING#11.1.2.0] [SRC_METHOD: logTimeEnd] PERF: 000041: 0000000001    GridResult                                  evaluateCalcCells: pass 1   

    [2013-09-16T12:07:12.976-04:00] [FinancialReporting0] [NOTIFICATION] [] [oracle.EPMFR.performance] [tid: Thread-37] [userId: <anonymous>] [ecid: 0000K4bKs0z6YNL6yRnZ6G1IDlyT000000,1:29968] [SRC_CLASS: com.hyperion.reporting.util.HRLogTimer] [APP: FINANCIALREPORTING#11.1.2.0] [SRC_METHOD: logTimeEnd] PERF: 000041: 0000000000    GridResult                                  evaluateCalcCells: pass 2   

    [2013-09-16T12:07:12.976-04:00] [FinancialReporting0] [NOTIFICATION] [] [oracle.EPMFR.performance] [tid: Thread-37] [userId: <anonymous>] [ecid: 0000K4bKs0z6YNL6yRnZ6G1IDlyT000000,1:29968] [SRC_CLASS: com.hyperion.reporting.util.HRLogTimer] [APP: FINANCIALREPORTING#11.1.2.0] [SRC_METHOD: logTimeEnd] PERF: 000041: 0000000000    GridResult                                  evaluateCalcCells: pass 3   

    [2013-09-16T12:07:12.977-04:00] [FinancialReporting0] [NOTIFICATION] [] [oracle.EPMFR.performance] [tid: Thread-37] [userId: <anonymous>] [ecid: 0000K4bKs0z6YNL6yRnZ6G1IDlyT000000,1:29968] [SRC_CLASS: com.hyperion.reporting.util.HRLogTimer] [APP: FINANCIALREPORTING#11.1.2.0] [SRC_METHOD: logTimeEnd] PERF: 000041: 0000000001    GridResult                                  evaluateCalcCells: pass 4   

    [2013-09-16T12:07:12.977-04:00] [FinancialReporting0] [NOTIFICATION] [] [oracle.EPMFR.performance] [tid: Thread-37] [userId: <anonymous>] [ecid: 0000K4bKs0z6YNL6yRnZ6G1IDlyT000000,1:29968] [SRC_CLASS: com.hyperion.reporting.util.HRLogTimer] [APP: FINANCIALREPORTING#11.1.2.0] [SRC_METHOD: logTimeEnd] PERF: 000041: 0000000000    GridResult                                  evaluateCalcCells: pass 0   

    [2013-09-16T12:07:12.978-04:00] [FinancialReporting0] [NOTIFICATION] [] [oracle.EPMFR.performance] [tid: Thread-37] [userId: <anonymous>] [ecid: 0000K4bKs0z6YNL6yRnZ6G1IDlyT000000,1:29968] [SRC_CLASS: com.hyperion.reporting.util.HRLogTimer] [APP: FINANCIALREPORTING#11.1.2.0] [SRC_METHOD: logTimeEnd] PERF: 000041: 0000000001    GridResult                                  evaluateCalcCells: pass 1   

    [2013-09-16T12:07:12.978-04:00] [FinancialReporting0] [NOTIFICATION] [] [oracle.EPMFR.performance] [tid: Thread-37] [userId: <anonymous>] [ecid: 0000K4bKs0z6YNL6yRnZ6G1IDlyT000000,1:29968] [SRC_CLASS: com.hyperion.reporting.util.HRLogTimer] [APP: FINANCIALREPORTING#11.1.2.0] [SRC_METHOD: logTimeEnd] PERF: 000041: 0000000000    GridResult                                  evaluateCalcCells: pass 2   

    [2013-09-16T12:07:12.979-04:00] [FinancialReporting0] [NOTIFICATION] [] [oracle.EPMFR.performance] [tid: Thread-37] [userId: <anonymous>] [ecid: 0000K4bKs0z6YNL6yRnZ6G1IDlyT000000,1:29968] [SRC_CLASS: com.hyperion.reporting.util.HRLogTimer] [APP: FINANCIALREPORTING#11.1.2.0] [SRC_METHOD: logTimeEnd] PERF: 000041: 0000000001    GridResult                                  evaluateCalcCells: pass 3   

    [2013-09-16T12:07:12.979-04:00] [FinancialReporting0] [NOTIFICATION] [] [oracle.EPMFR.performance] [tid: Thread-37] [userId: <anonymous>] [ecid: 0000K4bKs0z6YNL6yRnZ6G1IDlyT000000,1:29968] [SRC_CLASS: com.hyperion.reporting.util.HRLogTimer] [APP: FINANCIALREPORTING#11.1.2.0] [SRC_METHOD: logTimeEnd] PERF: 000041: 0000000000    GridResult                                  evaluateCalcCells: pass 4   

    [2013-09-16T12:07:12.979-04:00] [FinancialReporting0] [ERROR] [00063] [oracle.EPMFR.core] [tid: Thread-37] [userId: <anonymous>] [ecid: 0000K4bKs0z6YNL6yRnZ6G1IDlyT000000,1:29968] [SRC_CLASS: com.hyperion.reporting.contents.GridResult] [APP: FINANCIALREPORTING#11.1.2.0] [SRC_METHOD: logUnevaluatedCells] The maximum calculation limit of 5 has been reached. Further processing of this cell calculation will not occur

     

    SharedServices_SecurityClient.log

    [2013-09-16T11:11:42.626-04:00] [FinancialReporting0] [NOTIFICATION:16] [EPMCSS-20332] [oracle.EPMCSS.CSS] [tid: 12] [userId: <anonymous>] [ecid: 0000K4bKs0z6YNL6yRnZ6G1IDlyT000000,1:29943] [SRC_CLASS: com.hyperion.css.cache.CacheThread] [APP: FINANCIALREPORTING#11.1.2.0] [SRC_METHOD: buildCache] Unify cache done and cache object set to the cache manager. This is a status messages. No action required.

    [2013-09-16T11:14:33.113-04:00] [FinancialReporting0] [ERROR] [EPMCSS-07003] [oracle.EPMCSS.CSS] [tid: 11] [userId: <anonymous>] [ecid: 0000K4bLZ5s6YNL6yRnZ6G1IDlyT00000^,0] [SRC_CLASS: com.hyperion.css.common.CSSIdentityHelper] [APP: FINANCIALREPORTING#11.1.2.0] [SRC_METHOD: getValues] Failed to validate identity. Invalid identity admin. Check identity.

     

  • 2. Re: Frequent FR Server Crashes
    Neeraj Lahoti Journeyer
    Neeraj Lahoti Sep 17, 2013 9:50 PM (in response to 866532)
    Currently Being Moderated

    What is back end data source HFM or Essbase

  • 3. Re: Frequent FR Server Crashes
    866532 Newbie
    866532 Sep 18, 2013 6:00 AM (in response to Neeraj Lahoti)
    Currently Being Moderated

    The reports use HFM and Essbase data sources.

  • 4. Re: Frequent FR Server Crashes
    user10132385 Journeyer
    user10132385 Sep 19, 2013 4:46 AM (in response to 866532)
    Currently Being Moderated

    It seems to be some security issue.


    EPMCSS-00000: Failed to process request. Internal server error. Refer EPM Shared Services Security log file for related errors.

     

    Failed to validate identity. Invalid identity admin. Check identity.

Actions

Legend

  • Correct Answers - 10 points
  • Helpful Answers - 5 points