7 Replies Latest reply on Nov 7, 2012 11:27 AM by 967968

    Essbase.sec corrupt

    967968
      Hello all.

      Some days ago we had to restart Essbase in order to activate some new config settings. But Essbase wouldn't start. We got the following error message on startup:

      Fatal Error: Invalid record in security file. Restart Essbase using the latest backup security file, or set the ENABLESWITCHTOBACKUPFILE.

      We switched to an essbase.sec from the day before and Essbase started. Then, some days later we once again had to restart the Essbase service, and then the exact thing happened once again. I started digging into different log files and I've found the following:
      - A couple of days before the first restart of the Essbase service I see the following error message in the Essbase.log:

      [Wed Oct 03 00:42:28 2012]Local/ESSBASE0///11068/Error(1056794)
      Creation of backup file [E:\Oracle\EssbaseServer\bin\ESSBASETS_1349217747.BAK] failed with error status [1]

      The secfile backup occurs every 5 minutes and have completed successfully every time since march 2012 (when we also had similar problems with corruption of the secfile).
      - Just before the error I see that a refresh of Planning security filters is going on (triggered by a batch job).
      - After we got Essbase up and running the first time with the secfile from the day before (but after the the first occurence of the error message "Creation of backup file...", which happened a day before that) the backup of the secfile completes successfully for a little while and then fails again with the same error message. I once again notice that a refresh of Planning security filters is going on right before the error occurs (triggered manually by a user)
      - The exact same things as the previous point happened when we got Essbase up and running the second time.

      My hypothesis is that something bad happened to the secfile when the first "Creation of backup fil..." error message appeared in the log file. And when Essbase was restarted two days later the error kicked in. I suspect we have som issues with our security. I wonder for instance what would happen if by accident an msad user was removed from msad (not Hyperion) and a Planning security refresh takes place...

      I should also mention that after we got Essbase up and running the first and second time I notice the following error message some minutes after the first occurence of the "Creation of backup fil..." error message:

      [Fri Oct 05 12:15:04 2012]Local/ESSBASE0///7424/Info(1051001)
      Received client request: Get Security Exception in thread "Mistral" java.lang.OutOfMemoryError: GC overhead limit exceeded
           at java.util.Arrays.copyOf(Arrays.java:2882)
           at java.lang.AbstractStringBuilder.expandCapacity(AbstractStringBuilder.java:100)
           at java.lang.AbstractStringBuilder.append(AbstractStringBuilder.java:390)
           at java.lang.StringBuilder.append(StringBuilder.java:119)
           at java.lang.StringBuilder.append(StringBuilder.java:115)
           at javax.naming.ldap.Rdn.toString(Rdn.java:275)
           at java.lang.String.valueOf(String.java:2826)
           at java.lang.StringBuilder.append(StringBuilder.java:115)
           at javax.naming.ldap.LdapName.toString(LdapName.java:617)
           at com.hyperion.css.spi.AbstractJNDICacheBuilder.processChildren(AbstractJNDICacheBuilder.java:54)
           at com.hyperion.css.spi.impl.msad.MSADCacheBuilder.populateMSADCache(MSADCacheBuilder.java:196)
           at com.hyperion.css.spi.impl.msad.MSADCacheBuilder.buildCache(MSADCacheBuilder.java:65)
           at com.hyperion.css.spi.impl.msad.MSADProvider.createCache(MSADProvider.java:5309)
           at com.hyperion.css.cache.ProviderCacheThread.run(ProviderCacheThread.java:32)
      java.lang.NullPointerException
           at com.hyperion.css.cache.CacheThread.unifyCache(CacheThread.java:209)
           at com.hyperion.css.cache.CacheThread.buildCache(CacheThread.java:106)
           at com.hyperion.css.cache.CacheThread.run(CacheThread.java:68)
      Mode (from user [superadmin@Native Directory])


      I hope some of you gurus can shed som light on this because I'm pretty sure the same thing will happen again the next time we restart Essbase.

      Kind regards
      Arild.
        • 1. Re: Essbase.sec corrupt
          John A Booth
          Hi Alrid,

          What generally is going on when you see this type of behavior is you have lots of objects in your directory (ldap/MSAD) and you need to implement a filter and/or disable MSAD groups. Of course if you use MSAD groups you have a few other options too.

          Read the four below My Oracle Support articles. Easiest thing to do is increase your heap size, next look at a hyperion group with all of your users and use that as a filter, and third definitely disable MSAD groups if these are not in use.

          See:
          1331979.1 - Disable MSAD Groups
          1473163.1 - Increase Java Heap Size
          1227144.1 - Using filter to reduce users
          1068470.1 - How to set filters

          Regards,

          John A. Booth
          http://www.metavero.com
          1 person found this helpful
          • 2. Re: Essbase.sec corrupt
            967968
            Hello John and thanks for your quick answer!

            We will implement what is described in the articles you mention.

            That will hopefully take care of the memory issues. Will it also fix the problems with the Essbase.sec file? If not, do you have any suggestions about what to do next?

            Regards
            Arild.

            Edited by: 964965 on 16.okt.2012 09:36
            • 3. Re: Essbase.sec corrupt
              John A Booth
              I believe it will definitely help avoid the issues you have seen. You will of course need to restore a good .sec file from a backup.

              Regards,

              John A. Booth
              http://www.metavero.com
              1 person found this helpful
              • 4. Re: Essbase.sec corrupt
                967968
                OK, I will implement your suggestions and hopefully the sun shines again:-)

                I'll post the results here when I'm done.

                Thanks a lot John!

                Regards
                Arild.

                Edited by: 964965 on 17.okt.2012 09:21
                • 5. Re: Essbase.sec corrupt
                  967968
                  Hello again John!

                  Yesterday I finally had the opportunity to take the system down and do some testing.

                  First I did some testing without making any changes, just to see if I could isolate the problem application. I did it in the following manner:
                  - Restart Essbase with healthy secfile.
                  - Refresh Planning security from application A. Then watch the Essbase.log until an incremental backup of the Essbase.sec was completed. If successfull backup, I repeat the process with the Planning application B and so on.
                  - I finally isolated three applications which, after planning security refresh, lead to unsuccessful incremental backup of Essbase.sec.
                  - Then I applied an msad group filter in HSS as you suggested, restarted the whole environment (Essbase, HSS, Planning, ...) and also put back the healthy secfile.
                  - I then repeated the process with the three last mentioned applications and refreshed security filters and wathed the essbase.log. The first application was followed by a successful incr. backup of secfile! And this is a big application with lots of filters. Also, the essbase agent used 130MB RAM instead of 400MB, which was the normal amount. But when I refreshed filters for the second application Essbase shut down abnormally! This application however is small with not so many filters. Here follows excerpts from some log files at the time Essbase went down:

                  ESSBASE.LOG:

                  [Tue Oct 30 21:18:31 2012]Local/ESSBASE0///5220/Info(1056797)
                  Incremental security backup started by SYSTEM [DAEMON THREAD]. The file created is [E:\Oracle\EssbaseServer\bin\ESSBASETS_1351628311.BAK]

                  [Tue Oct 30 21:18:31 2012]Local/ESSBASE0///11276/Info(1051001)
                  Received client request: Verify Filter (from user [superadmin@Native Directory])

                  [Tue Oct 30 21:18:31 2012]Local/ESSBASE0///7888/Info(1051001)
                  Received client request: Set Filter (from user [superadmin@Native Directory])

                  [Tue Oct 30 21:18:31 2012]Local/ESSBASE0///5220/Info(1008106)
                  Exception error log [D:\Oracle\Middleware\user_projects\P114270071\diagnostics\logs\essbase\essbase_0\log00001.xcp] is being created...

                  [Tue Oct 30 21:18:32 2012]Local/ESSBASE0///5220/Info(1008107)
                  Exception error log completed D:\Oracle\Middleware\user_projects\P114270071\diagnostics\logs\essbase\essbase_0\log00001.xcp please contact technical support and provide them with this file

                  [Tue Oct 30 21:18:42 2012]Local/ESSBASE0///5220/Info(1054018)
                  RECEIVED ABNORMAL SHUTDOWN COMMAND - ESSBASE TERMINATING




                  ESSBASE AGENT LOG:

                  ]Local/ESSBASE0///11552/Info(1051001)
                  Received client request: Set Filter Users (from user [superadmin@Native Directory])

                  [Tue Oct 30 21:18:31 2012]Local/ESSBASE0///10628/Info(1051001)
                  Received client request: Get User/Group Info (from user [superadmin@Native Directory])

                  [Tue Oct 30 21:18:31 2012]Local/ESSBASE0///6100/Info(1051001)
                  Received client request: Get User Type (from user [superadmin@Native Directory])

                  [Tue Oct 30 21:18:31 2012]Local/ESSBASE0///5220/Info(1056797)
                  Incremental security backup started by SYSTEM [DAEMON THREAD]. The file created is [E:\Oracle\EssbaseServer\bin\ESSBASETS_1351628311.BAK]

                  [Tue Oct 30 21:18:31 2012]Local/ESSBASE0///11276/Info(1051001)
                  Received client request: Verify Filter (from user [superadmin@Native Directory])

                  [Tue Oct 30 21:18:31 2012]Local/ESSBASE0///7888/Info(1051001)
                  Received client request: Set Filter (from user [superadmin@Native Directory])

                  --------
                  12/10/30 21:18:38 Ping process
                  --------
                  [Tue Oct 30 21:18:42 2012]Local////Error(1042013)
                  Network error [10054]: Cannot Receive Data
                  [Tue Oct 30 21:18:42 2012]Local////Error(1042012)
                  Network error [10054]: Cannot Send Data




                  APPLICATION LOG:

                  [Tue Oct 30 21:18:31 2012]Local/DK12Dk///4036/Info(1013205)
                  Received Command [Verify Filters]

                  [Tue Oct 30 21:18:42 2012]Local/DK12Dk///1460/Error(1042013)
                  Network error [10054]: Cannot Receive Data

                  [Tue Oct 30 21:18:42 2012]Local/DK12Dk///4036/Info(1013207)
                  RECEIVED SHUTDOWN COMMAND - SERVER TERMINATING

                  [Tue Oct 30 21:18:42 2012]Local/DK12Dk///4036/Info(1019018)
                  Writing Parameters For Database [Bem]

                  [Tue Oct 30 21:18:42 2012]Local/DK12Dk///4036/Info(1019018)
                  Writing Parameters For Database [Dk]

                  [Tue Oct 30 21:18:42 2012]Local/DK12Dk///4036/Info(1008106)
                  No message for message #1008106 in message database

                  [Tue Oct 30 21:18:42 2012]Local/DK12Dk///4036/Info(1008107)
                  No message for message #1008107 in message database

                  [Tue Oct 30 21:18:42 2012]Local/DK12Dk///4036/Info(1002089)
                  No message for message #1002089 in message database




                  EXCEPTION FILE SERVER LEVEL:

                  Current Date & Time: Tue Oct 30 21:18:31 2012
                  Process Type: Server
                  Application Name:
                  Database Name:
                  Exception Log File: D:\Oracle\Middleware\user_projects\P114270071\diagnostics\logs\essbase\essbase_0\log00001.xcp
                  Current Thread Id: 5220
                  Exception Code: 0xC0000005=Access Violation
                  Exception Flags: 0x00000000=Continuable
                  Exception Address: 0x00000000004DA59E
                  Exception Parameters: 2
                  Exception Parameter 0: 0x00000000=Read Violation
                  Exception Parameter 1: 0x00000000 (Virtual Address)





                  EXCEPTION FILE DATABASE LEVEL:

                  Current Date & Time: Tue Oct 30 21:18:42 2012
                  Process Type: Application
                  Application Name: DK12Dk
                  Database Name: Bem
                  Exception Log File: D:\Oracle\Middleware\user_projects\P114270071\diagnostics\logs\essbase\essbase_0\app\DK12Dk\Bem\log00001.xcp
                  Current Thread Id: 4036
                  Exception Code: 0xC0000005=Access Violation
                  Exception Flags: 0x00000000=Continuable
                  Exception Address: 0x00000000604E95EF
                  Exception Parameters: 2
                  Exception Parameter 0: 0x00000000=Read Violation
                  Exception Parameter 1: 0x00000000 (Virtual Address)


                  Do you have any recommendations about what to do next?

                  Kind regards
                  Arild Bjørsvik.
                  • 6. Re: Essbase.sec corrupt
                    John A Booth
                    Hi Arilnd,

                    A few thoughts.

                    Do you have an existing Oracle ticket going? If not I would suggest getting a Sev 2 ticket entered with the background you have.

                    From a security perspective are you using groups within groups or some type of very complex security on the second application? Before the system became unstable are you able to locate specific changes that made it even more complex?

                    What specific version are you on right now? 11.1.2.1 has a 104 patch which came out recently and I am sure 11.1.2.0 has had patches in recent history.
                    As it appears to be caused by a planning application I would also pursue planning patches.

                    Regards,

                    John A. Booth
                    http://www.metavero.com
                    1 person found this helpful
                    • 7. Re: Essbase.sec corrupt
                      967968
                      Hello John!

                      Yes, I have now opened a ticket with Oracle and I'll let you know what they say about it.

                      I'm checking the complexity of the security.

                      We will probably try out a patch rather soon I hope.

                      Kind regards
                      Arild Bjørsvik.