4 Replies Latest reply on Sep 19, 2013 11:46 AM by AmarnathK

    Frequent FR Server Crashes

    866532
    866532 Sep 16, 2013 6:21 PM

      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
          866532 Sep 16, 2013 6:31 PM (in response to 866532)

          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-Oracle
            Neeraj Lahoti-Oracle Sep 18, 2013 4:50 AM (in response to 866532)

            What is back end data source HFM or Essbase

            • 3. Re: Frequent FR Server Crashes
              866532
              866532 Sep 18, 2013 1:00 PM (in response to Neeraj Lahoti-Oracle)

              The reports use HFM and Essbase data sources.

              • 4. Re: Frequent FR Server Crashes
                AmarnathK
                AmarnathK Sep 19, 2013 11:46 AM (in response to 866532)

                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.