Why... Why... Why?
This blog is dedicated to documenting error resolution and other tidbits that I discover while working as a Consultant in the Oracle EPM (Hyperion) field. As much of my job revolves around issue resolution, I see an opportunity to supplement the typical troubleshooting avenues such as the Oracle Knowledgebase and Oracle Forums with more pinpointed information about specific errors as they are encountered. Beware, the information found in this blog is for informational purposes only and comes without any warranty or guarantee of accuracy.

EPMVirt: Create your own Oracle Hyperion Virtual Environment:

Saturday, April 23, 2016

Troubleshooting HFM 11.1.2.4 on Windows

HFM on 11.1.2.4 and higher versions has a significantly different architecture than previous versions. This difference makes troubleshooting issues much harder. The old tricks seem out of date and it is easy to feel lost in the new version. Unfortunately, getting lost and unable to solve problems can lead to downtime and project delays. I wanted to share some basic tips to help get started in 11.1.2.4. Specifically, I wanted to focus on Windows because I have covered Linux in previous posts.

First, let's take a real error while creating a brand new HFM application.





Here we get the error: EPMHFM-66054: The system was unable to find the Datasource process for application. Essentially each HFM application spawns its own process in HFM and this application crashed while trying to initialize. This could be due to any number of things...



The first thing to note is the old HFMErrorLogViewer from previous versions is gone. The HFMErrorLogViewer was a great tool because it collected all the backend log messages into one convenient place. Now it looks like things are spread out over many logs. 

First, HFM is broken down at a high level into the Weblogic/ADF components and the Java HFM Wrapper Engine. They appear as Windows services,


The Web Tier consists of the Weblogic applications & UI. These logs can be found under the WebLogic domain,

The Java Server is the more interesting of the two for debugging because most significant errors can be traced to the backend. One thing to realize is HFM is still only partially Java based. There are still significant portions of HFM representing legacy code written in C. These low level functions are wrapped into this Java framework to make it look seamless. 

Let's take a look at some of the backend logs.


One of the main logs to investigate is under 
Oracle\Middleware\user_projects\epmsystem1\diagnostics\logs\hfm
The hsx-server log will have most details regarding the HFM backend service, similiar to the messages you would see previously in the HFMErrorLogViewer.

oracle-epm-fm-hsx-server.log

startDatasourceProcess] Starting a new datasource process for the application TESTHFM999[2016-04-23T00:29:43.500-07:00] [FM] [NOTIFICATION] [] [oracle.FM.HSXDSLM.oracle.epm.fm.dslm.DatasourceProcessManager] [tid: 12] [ecid: 005CI7TJTRS8dplqwsedMG0006Vu001PXQ,0:1:4] [SRC_CLASS: oracle.epm.fm.dslm.DatasourceProcessManager] [SRC_METHOD: getDSCommandLineArguments]  Starting the application TESTHFM999 on the ports : DSManagementPort port 10001 and DSHandler Port 10002
[2016-04-23T00:29:43.532-07:00] [FM] [NOTIFICATION] [] [oracle.FM.HSXDSLM.oracle.epm.fm.dslm.DatasourceProcessManager] [tid: 12] [ecid: 005CI7TJTRS8dplqwsedMG0006Vu001PXQ,0:1:4] [SRC_CLASS: oracle.epm.fm.dslm.DatasourceProcessManager] [SRC_METHOD: isSingleInstance]  Is Single Instance ? true
[2016-04-23T00:29:43.532-07:00] [FM] [ERROR] [EPMHFM-65925] [oracle.FM.HSX.SERVER.oracle.epm.fm.common.HsxServerConfig] [tid: 12] [ecid: 005CI7TJTRS8dplqwsedMG0006Vu001PXQ,0:1:4] [SRC_CLASS: oracle.epm.fm.common.HsxServerConfig] [SRC_METHOD: getDSHangTimeoutPeriod] 
... 
[2016-04-23T00:29:44.485-07:00] [FM] [NOTIFICATION] [] [oracle.FM.HSXDSLM.oracle.epm.fm.dslm.DatasourceProcessManager] [tid: 14] [ecid: 005CI7TJTRS8dplqwsedMG0006Vu001PXQ,0:1:4:21] [SRC_CLASS: oracle.epm.fm.dslm.DatasourceProcessManager] [SRC_METHOD: onProcessFailed] Datasource process for application TESTHFM999 stopped.
[2016-04-23T00:29:44.500-07:00] [FM] [NOTIFICATION] [] [oracle.FM.HSXDATAACCESS.oracle.epm.fm.dal.manager.ApplicationManagerDALImpl] [tid: 14] [ecid: 005CI7TJTRS8dplqwsedMG0006Vu001PXQ,0:1:4:21] [SRC_CLASS: oracle.epm.fm.dal.manager.ApplicationManagerDALImpl] [SRC_METHOD: deleteCCLockRecordsForServer]  Table TESTHFM999_CC_LOCKS does not exist
[2016-04-23T00:29:44.563-07:00] [FM] [WARNING] [] [oracle.FM.HSXDSLM.oracle.epm.fm.dslm.DatasourceManagerImpl] [tid: 12] [ecid: 005CI7TJTRS8dplqwsedMG0006Vu001PXQ,0:1:4] [SRC_CLASS: oracle.epm.fm.dslm.DatasourceManagerImpl] [SRC_METHOD: pingDatasource] Unable to invoke ping on XDS management service for the application TESTHFM999 , 

From this log it is evident that each HFM application creates a new datasource. A datasource is a separate process that handles all the processing for a particular application. The datasource process is launched after creating the application, or on the fly as the application is accessed. 

This spawned datasource process creates a new logfile for each application. For instance, a log file is created with the application name, such as xfm.odl.TESTHFM000-1.log. 

Having a look:

xfm.odl.TESTHFM000-1.log

[2016-04-23T00:29:44.453951-07:00] [XFM] [ERROR:1] [EPMHFM-07392] [XFM] [ecid: XDS.0000.0000.0000.0001] [File: XfmODBC.cpp] [Line: 203] [userId: ] [appName: TESTHFM999] [pid: 19988] [tid: 20008] [host: ] [nwaddr: ] [errorCode: 800402B5] [srcException: NotSpec] [errType: 1] [dbUpdate: 2] [11.1.2.4.200.5149] An unknown error occurred in an ODBC object. [[1 record: SQLSTATE = 08001; NATIVE ERROR = -4; MSG = [DataDirect][ODBC Oracle Wire Protocol driver][Oracle]Connection Dead. This may have occurred because the server requires Oracle Advanced Security. To enable the driver to use OAS, please use the DataIntegrityLevel and/or EncryptionLevel connect options.]] 
[2016-04-23T00:29:44.453951-07:00] [XFM] [ERROR:1] [EPMHFM-07406] [XFM] [ecid: XDS.0000.0000.0000.0001] [File: XfmODBC.cpp] [Line: 615] [userId: ] [appName: TESTHFM999] [pid: 19988] [tid: 20008] [host: ] [nwaddr: ;] [errorCode: 800402C3] [srcException: XfmExc] [errType: 1] [dbUpdate: 1] [11.1.2.4.200.5149] An error occurred in creating an ODBC connection. [[08001]] 
[2016-04-23T00:29:44.469577-07:00] [XFM] [ERROR:1] [EPMHFM-07406] [XFM] [ecid: XDS.0000.0000.0000.0001] [File: XfmODBC.cpp] [Line: 700] [userId: ] [appName: TESTHFM999] [pid: 19988] [tid: 20008] [host: ] [nwaddr: ] [errorCode: 800402C3] [srcException: XfmExc] [errType: 1] [dbUpdate: 1] [11.1.2.4.200.5149] An error occurred in creating an ODBC connection. [[Failed to create DB connection.]] 
So it looks like ODBC is involved here. Essentially, the underlying database connection in HFM is now ODBC. This was done to support HFM on Linux. The ODBC layer is how Oracle choose to make the code OS agnostic.

The ODBC connection is controlled by the Merant DataDirect 7.1 ODBC Driver. This is similar to how external Essbase database connections were created in the past. Looking at the error message, we are getting Connection Dead. This is actually a common problem with the ODBC DataDirect drivers and encrypted database connections. It is possible to reproduce this outside of HFM by testing the ODBC driver by hand:

Open Microsoft ODBC Manager, and add a connection.

HFM uses the DataDirect 7.1 Oracle Wire Protocol

Entering in the basic database connection details:

The exact error message appears, outside of HFM. 




This error message also happens to indicate where to look to solve the issue. In this case, the Oracle Database Listener connection requires an encrypted connection. Unsecured connections are rejected. So we can simply configure the ODBC connection to use the same encryption as the Oracle Listener.

sqlnet.crypto_checksum_server = REQUIRED
sqlnet.crypto_checksum_types_server = (SHA1)
sqlnet.encryption_types_server = (AES256)

Oracle Database Listener Settings


In the ODBC connection there are Advanced Security parameters which allow us to easily match the listener settings.






This is great. However, now we need to figure out where the ODBC connection is stored in HFM in order to configure these advanced properties.

HFM creates a new datasource in the Oracle client called HFMTNS. This info is entered during config tool, and automatically added to the tnsnames.ora in the HFM Database client folder
D:\Oracle\Middleware\dbclient64\network\admin. The ODBC connection leverages this HFMTNS connection information.

Taking a step back, since all of this is actually wrapped into a Java Server container, one additional place for logs is the Windows service start log:

D:\Oracle\Middleware\user_projects\epmsystem1\diagnostics\logs\services

HyS9FinancialManagementJavaServer-sysout.log


Here there is some very interesting information about how this ODBC connection is stored.

[2016-04-23T10:29:07.179806-07:00] XDS: XFMDataSource process starting...[2016-04-23T10:29:07.179806-07:00] XDS: Processing command line arguments...[2016-04-23T10:29:07.179806-07:00] XDS: Initializing XfmJHsxServerWrapper...[2016-04-23T10:29:07.179806-07:00] XDS: Getting database settings from HIT registry ...[2016-04-23T10:29:07.257929-07:00] XDS: Transforming DB connect info from JHsxServer into a DB connect string[2016-04-23T10:29:07.257929-07:00] Connection string: DRIVER={DataDirect 7.1 Oracle Wire Protocol};SRVR=HFMTNS;UID=...;PWD=**********;ENS=1;AN=HFM[2016-04-23T10:29:07.257929-07:00] XDS: Initializing static parameters...[2016-04-23T10:29:07.257929-07:00] XDS: Initializing critical errors log...[2016-04-23T10:29:07.257929-07:00] XDS: Critical errors log: D:\Oracle\Middleware\user_projects\epmsystem1\diagnostics\logs\hfm\TEST23.oracle_critical_errors.log[2016-04-23T10:29:07.257929-07:00] XDS: Initializing ODL logging...Found trace level'TRACE:32' in the logger node[2016-04-23T10:29:07.367305-07:00] XDS: Initializing DB logging...[2016-04-23T10:29:07.820454-07:00] XDS: Failed to run XFMDataSource. Unexpected error occured ...[2016-04-23T10:29:07.836077-07:00] XDS: Right before exit
From the log message it looks like the ODBC connection is created on the fly by transforming the database connection information used by the Java HFM Service, JHsxServer. This comes from the database credentials used when running the HFM config tool during configuration. I find this design unfortunate because there are going to be slight differences between how Java drivers and the DataDirect drivers work for non trivial connections. Looking at the Config Tool advanced properties, there are options for SSL database connections, but all are focused on JDBC (Java) connectivity.

In this case, we see that the DataDirect based encryption properties cannot be set. Since there does not seem to be any way to change the advanced properties, The investigation has hit a dead end and Oracle SR needs created to get this fixed.


21 comments:

  1. Hi Nicholas, Were you able to fix this? We have a similar situation, We created few apps using copy app utility. The apps are throwing this error intermittently and the log message is related to ODBC connectivity. Could you please let me know if you found a way to get around this?

    Thanks much!

    ReplyDelete
    Replies
    1. We are still working through an SR with Oracle. No fix yet...
      Thanks
      Nick

      Delete
  2. Hi Nick,

    I created another duplicate app using "Duplicate Application" option in Consolidation Administration and im able to open without errors. Would it have anything to do with AppCopy utility? Earlier, we used app copy utility to create the duplicate app. Oracle doesn't seem to be helpful

    ReplyDelete
  3. Hi Nick,
    We have also got similar error.
    Were you able to resolve this issue?
    Best Regards,
    Tejaswini

    ReplyDelete
  4. Hi,

    Is this issue resolved? I am having same issue while trying open Hfm app from workspace.
    Appreciate your help!

    Thanks
    HV

    ReplyDelete
  5. Right after we encrypted our HFM database we were not able to open HFM app and got the same errors listed.Anyone found solution related to this issue ? Opened SR as well to get more details what exactly we need to do on client side to connect to encrypted databases.
    Thanks,
    Vani.

    ReplyDelete
  6. Looks like we have confirmation that a fix is coming in the HFM 11.1.2.4.250 PSU. The rough ETA on this PSU is July.

    ReplyDelete
    Replies
    1. Hello Nicholas,
      Did oracle confirm this as a bug ? do you have the bug number for reference ? .250 PSU seems to be a long way ! We are having a huge back log due to this issue.

      Delete
  7. I am also facing a similar issue. But does this mean there is no workaround till the 11.1.2.3.250 PSU is out.

    ReplyDelete
  8. Does this mean that we do not have a workaround till 11.1.2.4.250 PSU is released.

    ReplyDelete
  9. Hi, Are we able to fix this yet. We are using SQL Server as Database.

    ReplyDelete
  10. Hello Nick, This is a great blog. I am so glad to find it as I was troubleshooting an issue with HFM database connectivity issue. So good to see you after a long long time, man.

    ReplyDelete
  11. Hello,

    Were you able to fix this issue? We are facing similar issue after using Maintenance Release option to upgrade our 11.1.2.1 apps.

    thanks,
    Suhas

    ReplyDelete
  12. Hello Nick,
    Came across this blog on my search for XFMDataSource Module performance issue.
    We just migrated HFM from 2.2 to 2.4 with patch HFM 205 and we are noticing when we run HFM Task Flow of Native Data Extract, the XFMDataSource Module goes 100% on CPU usage and sometimes the server gets hung. Have you experienced similar behavior.
    In our HFM 2.2, this behavior does not occur.
    Thanks,
    Azmat Bhatti

    ReplyDelete
  13. We are facing the exactly same issue, we have also applied the latest [11.1.2.4.206.5284] patch set but still not able to open HFM Application. Did you get any solution for this issue??

    ReplyDelete
  14. Please provide more details in order to create a new application, we are using 11.1.2.4.204 do we need to update on that PSU?

    ReplyDelete
  15. Hi, I am also facing the same error. but I am using sql server. I followed the steps not get succeed.
    I tried sql server protocol instead of adding oracle wire protocol. Is it correct or do I need to do anything else.

    ReplyDelete
  16. I am getting below error message when i open HFM Application and version HFM 11.1.2.4.0.79

    EPMHFM-66054: The system was unable to find the datasource process for application

    Could you please suggest how to reslove this issue.

    ReplyDelete
  17. Hello Nicholas,

    Getting issue described in Oracle DOC 2408794.1.
    We are using Microsoft SQL Server and it seems that there ODBC connection drops.
    As mentioned in your article that HFM creates the ODBC connection on the fly, is there a way to make HFM to add KeepAlive parameters and timeout parameters so that HFM can include in the on-the-fly ODBC string?
    This is for MS SQLServer database.

    Regards

    Bash

    ReplyDelete
  18. Hi Nick I am facing similar issue. Any solution on this. I even tried latest hfm patch but no luck.

    ReplyDelete
  19. Hi Nick, we are having the following issue. We have developed a HFM Web Service using the Java API's which updates the application data. With Hyperion version 11.1.2.4 it worked OK, with version 11.2 I'm getting the following message with XFM
    [2020-06-18T14:34:53.790019+00:00] [XFM] [ERROR:1] [EPMHFM-00000] [XFM] [ecid: 0000NB7qe1d3JByr04zW6F1UurLA000005] [File: c:\nsh00dph_build_view\hfm\source\session\xfmdata\cxfmdatafileparser.cpp] [Line: 233]
    Any help would be much appreciated
    Thanks
    Graham

    ReplyDelete