Library Access

Once upon a time several people were working on several different applications in our development environment.  We were adjusting shared dimensions, building and deleting HFM applications, and generally kicking sand around the playground.

http://aminoapps.com/page/cartoon/9847425/forget-the-internet-when-you-have-a-library-card-arthur-meme-contest

Then one day one of the developers couldn't get into the Application Library.  They got an error dialog with the title Requested Service not found and the helpful text:

----
Requested Service not found
----
Code: com.hyperion.awb.web.common.DimensionServiceException

Description: An error occurred processing the result from the server.

Actor: none

We also noticed we couldn't get to the Dimension Library.  And our scheduled taskflows had stopped working.  Since we could still login and open our HFM and Essbase applications we could rule out issues with foundation services, HFM, and Essbase.  Everything pointed to a problem with EPMA.

Analysis

While there were errors in the EPMA logs there wasn't an obvious smoking gun.  We engaged both Oracle support and our integration partner.  The odd thing about Oracle support support is that there is no option for the EPMA product.  All of the disciplines are cross-trained on EPMA but you have to really hunt around for someone who is an EPMA expert.

Between the three of us we noticed this set of errors in the DimensionServer.log:

[2017-08-26T23:57:18.764-04:00] [EPMADIM] [NOTIFICATION:32] [EPMADIM-1] [EPMADIM.Hyperion.DimensionServer.LibraryManager] [tid: EPMA Server Startup] [ecid: disabled,0] Starting 11.1.2.2.00 FixInvalidDynamicPropertyReferences task
[2017-08-26T23:57:19.263-04:00] [EPMADIM] [INTERNAL_ERROR:32] [EPMADIM-1] [EPMADIM.Hyperion.DimensionServer.LibraryManager] [tid: EPMA Server Startup] [ecid: disabled,0] Failed 11.1.2.2.00 FixInvalidDynamicPropertyReferences task    at System.String.InternalSubStringWithChecks(Int32 startIndex, Int32 length, Boolean fAlwaysCopy)
   at Hyperion.DimensionServer.DAO.LibraryManagerDAO.FixInvalidDynamicPropReferencesForDimension(Int32 libraryID, Int32 applicationID, Int32 dimensionID, String dynamicProps, Int32 propertiesDimID, Int32 dynamicPropsPropID)
   at Hyperion.DimensionServer.DAO.LibraryManagerDAO.<>c__DisplayClass64.<FixInvalidDynamicPropReferencesForLib>b__63(DALDatasetCommand command)
   at Hyperion.DataAccessLayerCore.DataAccessLayer.ExecLoadSQL(String SQL, Action`1 onSetParams, Action`1 onRead, DatabaseContext context)
   at Hyperion.DataAccessLayerCore.DataAccessLayer.ExecLoadSQL(String SQL, Action`1 onSetParams, Action`1 onRead)
   at Hyperion.DimensionServer.DAO.LibraryManagerDAO.FixInvalidDynamicPropReferencesForLib(Int32 libraryID)
   at Hyperion.DimensionServer.DAO.LibraryManagerDAO.FixInvalidDynamicPropReferences()
   at Hyperion.DimensionServer.LibraryManager.FixInvalidDynamicPropertyReferences()
[2017-08-26T23:57:19.294-04:00] [EPMADIM] [ERROR:32] [EPMADIM-1] [EPMADIM.Hyperion.DimensionServer.Global] [tid: EPMA Server Startup] [ecid: disabled,0] An error occurred during initialization of the Dimension Server Engine:  startIndex cannot be larger than length of string.
Parameter name: startIndex.    at Hyperion.DimensionServer.LibraryManager.FixInvalidDynamicPropertyReferences()
   at Hyperion.DimensionServer.Global.Initialize(ISessionManager sessionMgr, Guid systemSessionID, String sqlConnectionString)
[2017-08-26T23:57:19.294-04:00] [EPMADIM] [NOTIFICATION:32] [EPMADIM-1] [EPMADIM.Hyperion.DimensionServer.Utility.ChannelUtility] [tid: EPMA Server Startup] [ecid: disabled,0] Listening using IPv4

(I'm copying everything in the block above so it gets found by search engines.  But I highlighted the failed task that clued us into the solution.)  These errors were thrown each time EPMA services restarted.  And the errors started around the time the taskflows started failing.  Earlier in the log we just see the FixInvalidDynamicPropertyReferences task start and finish.  This looked like the culprit.

Solution

If you bingoogle “DimensionServer FixInvalidDynamicPropertyReferences” you find a couple articles that show the error above:

http://hyperion-epm-bi.blogspot.com/2016/01/epm-patch-11122500-breaks-epma.html
http://brovanture.com/news/blog-epm-patch-11-1-2-2-500-breaks-epma

Both articles note the cause as a specific Oracle patch.  It is an older patch that was superseded in our environments.  Since there were no recent patches applied we initially glossed over this.

But the fix is to run a SQL UPDATE statement to replace blank strings with NULL values:

UPDATE DS_Property_Dimension
   SET c_property_value = null
   FROM DS_Property_Dimension pd
      JOIN DS_Library lib
         ON lib.i_library_id = pd.i_library_id
      JOIN DS_Member prop
         ON prop.i_library_id = pd.i_library_id
            AND prop.i_dimension_id = pd.i_prop_def_dimension_id
            AND prop.i_member_id = pd.i_prop_def_member_id
      JOIN DS_Dimension d
         ON d.i_library_id = pd.i_library_id
            AND d.i_dimension_id = pd.i_dimension_id
  WHERE
      prop.c_member_name = 'DynamicProperties' AND
      pd.c_property_value IS NOT NULL AND pd.c_property_value = '';

Since we had exhausted all other avenues we replaced the UPDATE statement with a SELECT statement:

SELECT c_property_value
   FROM DS_Property_Dimension pd
      JOIN DS_Library lib
         ON lib.i_library_id = pd.i_library_id
      JOIN DS_Member prop
         ON prop.i_library_id = pd.i_library_id
            AND prop.i_dimension_id = pd.i_prop_def_dimension_id
            AND prop.i_member_id = pd.i_prop_def_member_id
      JOIN DS_Dimension d
         ON d.i_library_id = pd.i_library_id
            AND d.i_dimension_id = pd.i_dimension_id
  WHERE
      prop.c_member_name = 'DynamicProperties' AND
      pd.c_property_value IS NOT NULL AND pd.c_property_value = '';

The query returned a handful of records where the c_property_value was blank instead of NULL.  We ran the UPDATE query and after restarting the services the libraries, taskflows, and other EPMA features were available.

Conclusion

Prior to this we had issues with dimensions in one of the applications under development.  Part of fixing that required deleting and importing dimensions and adjusting attributes.  Our suspicion is that somewhere along the line blanks got imported instead of NULLs.

The first lesson is that EPMA issues can be tricky to resolve.  It seems odd that Oracle wouldn't have support staff focused on EPMA since that binds all of the other EPM featuers together along with foundation services.

The other lesson is that if you have an issue and find something that looks like it might help don't automatically discard it just because your situation is different.  Many times there is a way to check if the solution might apply to you.

More Trouble with Temp Files

The title of this post kind of gives away the plot before I even start the story.  But it does give me a chance to use this picture in my blog.

We update our HFM application metadata monthly.  We first deploy the changes in our development environment and test any required changes to member lists, rules, etc.  After the metadata is loaded into EPMA the HFM application has to be redeployed.  In this case the redeploy failed.  The message displayed was almost as useless as a tribble:

The custom error module does not recognize this error.

This is like something you would find on the DailyWTF, an error that tells you nothing more than it's an error.

In the Consolidation Administration tab was an error message that was a little more descriptive, but equally unenlightening.

Could not determine wsdl ports.

Searching the Oracle knowledge base and binggoolging turned up nothing useful.  In cases dealing with workspace we sometimes resolve unusual issues by clearing the browser cache and reopening the browser, but that didn't help.

The deployment failed at 6% which normally indicates a problem with EPMA.  Everything on the EPMA server looked normal and there were no obvious errors in the logs.  We tried restarting just the EPMA services which did not help.  We then restarted all the EPM services to close all connections, flush java caches, and try to clear up whatever was causing the error, but the redeploy still failed at the same step.

Then I checked the HFM server which in our case is a different host than EPMA.  The C: drive was almost full.  Because this is a dev environment I don't have any alerts configured so I didn't have advance warning of the problem.

Analysis

A handy tool for finding disk hogs is the sysinternals du utility.  It runs from the command line but the syntax is easy and you can use keyboard shortcuts to quickly drill down to find the problem folders.

While DU can scan a whole drive and find the hogging subfolders this can take a bit of time.  My strategy is to check just one level use the -L 1 paramenter, then drill down from there one level at a time.  This is usually a quicker way of finding the offending folder.

Here I look in the C:\Users folder because I suspect the problem is one of the profiles.  Clearly the problem is the profile taking over 5Gb with an account that starts with r and ends with v.

Using DOS shortcuts I hit the up arrow key to repeat the last command, add the backslash, type an [r] to start the username, use the [Tab] key to auto-fill the rest of the name, and press [Enter] to see results for the next level down.  Repeat this technique until you find the problem folder.

In this case it was the user profile of the service account that runs the HFM and other EPM servcies.  In the AppData\Local\Temp folder there were a bunch of temp files, many of them tens of megs in size.  After deleting all the temp files from previous years we freed up 5Gb of drive space and the deployment succeeded.

Even though this processing is handled by EPMA, there is still data being written to the HFM server.  Presumably this is so HFM has something to process once its turn in the deployment comes.

Conclusion

This is another episode where temp files don't get cleaned up after execution.  Also note that the .tmp files use the convention of a 4 hex digit as part of the name.  Had we not run out of drive space it is conceivable we would have run into name collision like we did with the Permanent Temporary Files.

This has become another task during the monthly maintenance where logs and other items get purged or truncated to keep the logs manageable and drive space clear.

What is curious in all of this is why aren't these temp files cleaned up as a matter of course?  While it makes sense to keep temp files around for troubleshooting if a process fails, surely whatever process generates these things could have a final step of cleaning up its droppings after it receives a success notice.  Even children know enough to clean up after their dog.

Permanent temporary files

We update the metadata for our HFM applications at least once per month.  Before updating the shared dimension library and deploying the production application we test all of the changes in our development environment.

During a recent test the deployment in development failed.  Usually a failure is during the deployment phase due to some misconfiguration in the new dimension members.  In this case the deployment failed during the initial export with the error message:

Detail : An error was encountered while executing the Application Export:  An error was encountered during export: The file exists.

Oracle Doc ID 1639083.1 shows the same error for Planning applications.  Because Planning and HFM both use the EPMA dimension and application libraries you can often extrapolate from the Planning solutions to solve HFM problems.

The article says the <SystemDrive>:\Windows\temp folder is full and the solution is to delete files from that directory.  But my C:\ drive wasn't full and there weren't many files in the \windows\temp directory.

Troubleshooting

According to the Oracle doc we were running out of file names.  But where?

The deployment is performed by EPMA and it fails before HFM starts its processing.  (Years ago an Oracle support engineer told me that during a deployment all the processing up to 20% is EPMA and after that it is HFM.  At any rate we don't get past the export so I know definitively that the problem was with EPMA.)

SysInternals has a bunch of powerful utilities for Windows systems.  I've been using these utilities since the WindowsNT days.  The author of the utilities, Mark Russinovich, was eventually hired as a technical fellow at Microsoft and is now the CTO of Azure.  He's one of the smartest guys you can follow and he's an engaging and articulate speaker if you see him give a presentation.

In this case I had to monitor the processes on the EPMA server to see what caused the failure.  From live.sysinternals.com I downloaded ProcMon and ran it on the EPMA server.  ProcMon will monitor everything on the server so you need to apply filters to isolate the information you want.  A handy technique is to let it capture for a few seconds, then stop the monitor, right-click any processes you don't care about such as explorer.exe, svchost.exe, your anti-virus software, etc and select Exclude.  This adds the exclusions to the current filter.  Repeat until you only have the handful of processes of interest, in this case anything related to EPMA.  Then clear the log, start the capture, and redeploy.

Once the deployment failed I stopped the capture and saved the results.  ProcMon captures access to the file system and registry as well as network and process thread events, so I removed everything except file system requests.  I didn't have to scroll down very far to see thousands of events from EPMA_Server.exe with a result of NAME COLLISION.  These are all in the AppData\Local\Temp directory of the user account under which the services run.

The files are named tmpXXXX.tmp where XXXX is appears to be a random set of 4 hex digits.  Some of these files are created during application deployment.  We do a nightly LCM export of EPMA for backup purposes and which also creates .tmp files.  Some of the .tmp files are XML properties of the applications and some are binary files.  Since this is our dev environment and we have many test applications, do regular deployments of HFM applications, and export EPMA nightly we ran out of the 65,535 possible names for the .tmp files.

Solution

As the Oracle doc implies, we just delete the .tmp files.  They are, after all, just temporary files in a temp directory.  Why Oracle doesn't delete them automatically or overwrite existing files instead of throwing an error is a topic for philosophers and software engineers to resolve.

Another location where files accumulate is \Oracle\Middleware\user_projects\epmsystem\tmp.  That folder holds temp files for shared dimension library updates, diagnostic framework, and web logic, among others.  Beneath this \tmp folder is a folder named EPMA that holds temp XML files with all properties of all dimensions in redeployed applications as well as temp ADS files created during LCM exports from EPMA.  Also beneath the \tmp folder is a folder oracle\tmp which has subfolders holding log files generated during HFM data syncs.

For us that issue came to light since we not only do nightly LCM exports of EPMA, we also have reporting applications that are updated nightly.  We use HFM taskflows to update the metadata, redeploy the applications, and run datasyncs to load data.  Because the .xml files generated during the redeploy can be large and we went through many rounds of testing, the data drive eventually filled to capacity which killed all activity on our EPMA server.

Our solution is regular maintenance to delete temp files in both the AppData\Local\Temp and the epmsystem\tmp folders on servers running the Hyperion EPMA Server service.  This task is easy enough to complete manually that I have not created an automated process for it.

But it is curious that Oracle doesn't automatically delete, or provide facilities for automatically deleting, these temporary files.  If you know of anything built into the products to address these temporary files please share that information in the comments below.