AnsweredAssumed Answered

Error after upgrade: policy server taking 22 hour for startup

Question asked by siteminderCA on Oct 5, 2016
Latest reply on Oct 21, 2016 by Patrick-Dussault

Policy server is taking 22 hour to come up.

 

please find the smps.log below:

 

[28540/1][Sat Oct 01 2016 15:00:22][CServer.cpp:254][INFO][sm-Server-03580] ************************************************************
[28540/1][Sat Oct 01 2016 15:00:22][CServer.cpp:254][INFO][sm-Server-03580] ***** SmTransact Version 12.52.0001.154 *****
[28540/1][Sat Oct 01 2016 15:00:22][CServer.cpp:254][INFO][sm-Server-03580] ************************************************************
[28540/1][Sat Oct 01 2016 15:00:22][CServer.cpp:4224][INFO][sm-Server-01840] Initializing smpolicysrv
[28540/1][Sat Oct 01 2016 15:00:22][SmAuthDsCache.cpp:253][INFO][sm-Directory-00450] UserAz cache is enabled for all policy resolutions
[28540/1][Sat Oct 01 2016 15:00:22][SmAuthDsCache.cpp:136][INFO][sm-Directory-00420] Initializing user directory cache
[28540/1][Sat Oct 01 2016 15:00:22][SmObjProvider.cpp:243][INFO][sm-Server-02830] Initializing policy store provider 'LDAP:'
[28540/1][Sat Oct 01 2016 15:00:22][SmObjProvider.cpp:282][INFO][sm-Server-02840] Loading of policy store provider extension DLL: 'smobjldapims' succeeded.
[28540/1][Sat Oct 01 2016 15:00:22][SmLdapPs.cpp:209][INFO][sm-Ldap-02140] SSL client init will not be attempted - no certificate database defined
[28540/1][Sat Oct 01 2016 15:00:23][smldaputils.cpp:529][INFO][sm-Ldap-00540] Opening policy store connection to LDAP server: ' IP:PORT'
[28540/1][Sat Oct 01 2016 15:00:24][SmLdapBulkSearch.cpp:152][CreateRoot][INFO][sm-xpsxps-01160] LDAP Provider Info String = Oracle Internet Directory
[28540/1][Sat Oct 01 2016 15:00:24][SmLdapBulkSearch.cpp:206][CreateRoot][INFO][sm-xpsxps-01120] LDAP Provider Version: orclcompatibleversion = OID 11.1.1.6.0
[28540/1][Sat Oct 01 2016 15:00:24][SmLdapBulkSearch.cpp:206][CreateRoot][INFO][sm-xpsxps-01120] LDAP Provider Version: orcldirectoryversion = OID 11.1.1.5.0
[28540/1][Sat Oct 01 2016 15:00:24][SmLdapBulkSearch.cpp:206][CreateRoot][INFO][sm-xpsxps-01120] LDAP Provider Version: supportedldapversion = 2
[28540/1][Sat Oct 01 2016 15:00:24][SmLdapBulkSearch.cpp:206][CreateRoot][INFO][sm-xpsxps-01120] LDAP Provider Version: supportedldapversion = 3
[28540/1][Sat Oct 01 2016 15:00:24][SmObjCache.cpp:402][INFO][sm-Server-02800] Preloading policy store cache
[28540/1][Sat Oct 01 2016 15:00:24][SmObjCache.cpp:415][INFO][sm-Server-02860] BulkFetch policy store
[28540/1][Sat Oct 01 2016 15:00:24][SmObjCache.cpp:418][INFO][sm-Server-02810] Precaching system configuration objects
[28540/1][Sat Oct 01 2016 15:04:10][SmObjCache.cpp:487][INFO][sm-Server-02820] Precaching each Policy Domain
[28540/1][Sat Oct 01 2016 15:04:10][SmObjCache.cpp:491][INFO][sm-Server-02870] BulkRelease policy store
[28540/1][Sat Oct 01 2016 15:04:10][PolicyCache.cpp:1294][INFO][sm-Server-02880] Building policy cache ...
[28540/1][Sat Oct 01 2016 15:04:11][PolicyCache.cpp:1387][INFO][sm-Server-02890] Building policy cache done
[28540/1][Sat Oct 01 2016 15:04:11][SmObjStore.cpp:1403][INFO][sm-Server-00050] Object store initialized
[28540/26][Sat Oct 01 2016 15:04:11][SmObjStore.cpp:1025][INFO][sm-Server-00110] Starting object store journal thread
[28540/27][Sat Oct 01 2016 15:04:11][SmObjStore.cpp:850][INFO][sm-Server-00070] Object store journal thread started
[28540/27][Sat Oct 01 2016 15:04:11][SmObjStore.cpp:851][INFO][sm-Server-00080] Journal commands refresh interval is 60 second(s)
[28540/27][Sat Oct 01 2016 15:04:11][SmObjStore.cpp:852][INFO][sm-Server-00090] Server command synchronization delta is 51 second(s)
[28540/27][Sat Oct 01 2016 15:04:11][SmObjStore.cpp:853][INFO][sm-Server-05250] Secondary cache failure timeout is 0 second(s)
[28540/1][Sat Oct 01 2016 15:04:11][Database.cpp:689][InitDB][INFO][sm-xpsxps-00120] Initializing XPS Version 12.52.0001.154
[28540/1][Sat Oct 01 2016 15:04:12][XPSLDAP.cpp:791][CreateRoot][INFO][sm-xpsxps-01160] LDAP Provider Info String = Oracle Internet Directory
[28540/1][Sat Oct 01 2016 15:04:12][XPSIO.cpp:451][InitialLoad][INFO][sm-xpsxps-00560] Database Transactions are 0.
[28540/1][Sat Oct 01 2016 15:04:17][XPSIO.cpp:478][InitialLoad][INFO][sm-xpsxps-00300] 2 Parameter(s) loaded from Policy Store, 2 total.
[28540/1][Sat Oct 01 2016 15:04:17][XPSIO.cpp:483][InitialLoad][INFO][sm-xpsxps-00330] Caching Policy Data...
[28540/27][Sat Oct 01 2016 16:03:21][SmObjStore.cpp:343][INFO][sm-Server-03330] Key Update Management is not enabled
[28540/27][Sat Oct 01 2016 16:03:21][SmObjStore.cpp:382][INFO][sm-Server-04720] Key distribution has been initiated by Policy Server
[28540/27][Sat Oct 01 2016 16:03:21][PolicyCache.cpp:1294][INFO][sm-Server-02880] Building policy cache ...
[28540/27][Sat Oct 01 2016 16:03:21][PolicyCache.cpp:1387][INFO][sm-Server-02890] Building policy cache done
[28540/1][Sun Oct 02 2016 12:19:30][XPSIO.cpp:502][InitialLoad][INFO][sm-xpsxps-00310] 37488 object(s) loaded from the Policy Store.
[28540/1][Sun Oct 02 2016 12:19:30][XPSIO.cpp:566][SetPolicyStoreID][INFO][sm-xpsxps-00430] Policy Store ID is "9e8b0883-0681-1010-b347-84f8add80000".
[28540/1][Sun Oct 02 2016 12:19:30][XPSAudit.cpp:719][GetAudit][INFO][sm-xpsxps-06870] XPS Auditing is enabled.
[28540/1][Sun Oct 02 2016 12:19:30][Database.cpp:752][InitDB][INFO][sm-xpsxps-03460] No validation warnings will be logged (controlled by CA.XPS::$LogValidationWarnings).
[28540/1][Sun Oct 02 2016 12:19:58][XPSIO.cpp:2051][MergeSmAndXPS][INFO][sm-xpsxps-00150] XPS Initialized. (34182, 0, 0)
[28540/1][Sun Oct 02 2016 12:19:58][XPS.cpp:901][Init][INFO][sm-xpsxps-00150] XPS Initialized.
[28540/1][Sun Oct 02 2016 12:19:58][NIDMgtCleanupRoutine.cpp:74][start][INFO][sm-xobfed-02966] NameID management cleanup thread started.
[28540/33][Sun Oct 02 2016 12:19:58][NIDMgtCleanupRoutine.cpp:129][waitForXPS][INFO][sm-xobfed-02969] NameID management cleanup thread running.
[28540/1][Sun Oct 02 2016 12:19:58][FedInterface.cpp:692][PostInitialize][INFO][sm-xobfed-02577] Successfully loaded smobjadapter.
[28540/1][Sun Oct 02 2016 12:19:58][SmPolicyServer.cpp:655][INFO][sm-Server-05320] XPS Initialization complete
[28540/1][Sun Oct 02 2016 12:19:58][SmPolicyServer.cpp:704][INFO][sm-Server-00770] Global Preferences: NestedSecurity=0
[28540/1][Sun Oct 02 2016 12:19:58][SmPolicyServer.cpp:712][INFO][sm-Server-00790] Nested Security:off
[28540/1][Sun Oct 02 2016 12:19:58][SmPolicyServer.cpp:743][INFO][sm-Server-00800] This policy server generates agent keys
[28540/1][Sun Oct 02 2016 12:19:58][SmPolicyServer.cpp:905][INFO][sm-Server-00830] This policy server is allowed to roll over trusted host shared secrets
[28540/1][Sun Oct 02 2016 12:19:58][DoManagement.cpp:1001][INFO][sm-Server-03670] Starting agent command management watchdog thread
[28540/34][Sun Oct 02 2016 12:19:58][DoManagement.cpp:974][INFO][sm-Server-03660] Starting agent command management thread
[28540/1][Sun Oct 02 2016 12:19:58][SmPolicyServer.cpp:2162][INFO][sm-Server-03690] Starting key management watchdog thread
[28540/1][Sun Oct 02 2016 12:19:58][SmPolicyServer.cpp:1741][INFO][sm-Server-03680] Starting journal management watchdog thread
[28540/35][Sun Oct 02 2016 12:19:58][DoManagement.cpp:851][INFO][sm-Server-00340] Agent Command Management thread started
[28540/1][Sun Oct 02 2016 12:19:58][SmSessionServer.cpp:297][INFO][sm-Server-06004] Session Services is disable
[28540/1][Sun Oct 02 2016 12:19:58][CServer.cpp:4245][INFO][sm-Server-01850] Initialized smpolicysrv
[28540/1][Sun Oct 02 2016 12:19:58][CServer.cpp:6387][INFO][sm-Server-03480] Initializing TLI
[28540/1][Sun Oct 02 2016 12:19:58][CServer.cpp:7976][INFO][sm-Server-02410] Initializing UDP
[28540/1][Sun Oct 02 2016 12:19:58][CServer.cpp:6450][INFO][sm-Server-03490] Starting TLI
[28540/1][Sun Oct 02 2016 12:19:58][CServer.cpp:6464][INFO][sm-Server-03500] Admin UDP port is up
[28540/1][Sun Oct 02 2016 12:19:58][CServer.cpp:8196][INFO][sm-Server-02420] TCP is up on 6 interfaces listening for incoming connections
[28540/1][Sun Oct 02 2016 12:19:58][CServer.cpp:4280][INFO][sm-Server-01860] Initialization done
[28540/1][Sun Oct 02 2016 12:19:58][CServer.cpp:4309][INFO][sm-Server-01870] Signal handler for SIGTERM and SIGINT is installed, thread id = 1
[28540/1][Sun Oct 02 2016 12:19:58][CServer.cpp:7652][INFO][sm-Server-04210] Clearing the server suspend state for reason 4. The server will resume serving requests.
[28540/1][Sun Oct 02 2016 12:19:58][CServer.cpp:3924][INFO][sm-Server-04230] The suspend timeout is 3600 seconds.
[28540/1][Sun Oct 02 2016 12:19:58][CServer.cpp:5582][INFO][sm-Server-02080] SiteMinder Policy Server is ready on localhost
[28540/1][Sun Oct 02 2016 12:19:58][CServer.cpp:5589][INFO][sm-Server-02090] Waiting for messages on thread id 1
[28540/36][Sun Oct 02 2016 12:20:01][SmPolicyServer.cpp:2133][INFO][sm-Server-00910] Starting key management thread
[28540/40][Sun Oct 02 2016 12:20:01][SmPolicyServer.cpp:1766][INFO][sm-Server-00900] Key management thread started.
[28540/37][Sun Oct 02 2016 12:20:13][SmPolicyServer.cpp:1713][INFO][sm-Server-00880] Starting journal management thread
[28540/41][Sun Oct 02 2016 12:20:13][SmPolicyServer.cpp:1662][INFO][sm-Server-00870] Journaling thread started, will delete commands older than 60 minutes

Outcomes