Symptoms
The sailpoint log contains multiple Early Heartbeat warnings, such as:
2022-04-24T21:19:34,931 WARN HeartbeatThread sailpoint.server.HeartbeatService:636 - Early heartbeat for server myserver
2022-04-24T21:19:34,931 WARN HeartbeatThread sailpoint.server.HeartbeatService:637 - Last: 4/24/2022 21:19:32 PM PDT
2022-04-24T21:19:34,931 WARN HeartbeatThread sailpoint.server.HeartbeatService:638 - Now: 4/24/2022 21:19:34 PM PDT
2022-04-24T21:19:34,932 WARN HeartbeatThread sailpoint.server.HeartbeatService:639 - Expected: 4/24/2022 21:19:42 PM PDT
You might also see concurrency issues such as OverlappingFileLockException from the FullTextService:
2022-04-24T21:19:33,148 ERROR ServerThread sailpoint.api.FullTextifier:412 - Exception building index
java.nio.channels.OverlappingFileLockException: null
at sun.nio.ch.SharedFileLockTable.checkList(FileLockTable.java:255) ~[?:1.8.0_181]
at sun.nio.ch.SharedFileLockTable.add(FileLockTable.java:152) ~[?:1.8.0_181]
at sun.nio.ch.FileChannelImpl.tryLock(FileChannelImpl.java:1108) ~[?:1.8.0_181]
at java.nio.channels.FileChannel.tryLock(FileChannel.java:1155) ~[?:1.8.0_181]
at org.apache.lucene.store.NativeFSLockFactory.obtainFSLock(NativeFSLockFactory.java:126) ~[lucene-core-8.2.0.jar:8.2.0 31d7ec7bbfdcd2c4cc61d9d35e962165410b65fe - ivera - 2019-07-19 15:05:56]
at org.apache.lucene.store.FSLockFactory.obtainLock(FSLockFactory.java:41) ~[lucene-core-8.2.0.jar:8.2.0 31d7ec7bbfdcd2c4cc61d9d35e962165410b65fe - ivera - 2019-07-19 15:05:56]
at org.apache.lucene.store.BaseDirectory.obtainLock(BaseDirectory.java:45) ~[lucene-core-8.2.0.jar:8.2.0 31d7ec7bbfdcd2c4cc61d9d35e962165410b65fe - ivera - 2019-07-19 15:05:56]
at org.apache.lucene.index.IndexWriter.<init>(IndexWriter.java:729) ~[lucene-core-8.2.0.jar:8.2.0 31d7ec7bbfdcd2c4cc61d9d35e962165410b65fe - ivera - 2019-07-19 15:05:56]
at sailpoint.fulltext.Builder.startLucene(Builder.java:299) [identityiq.jar:8.1 Build dfd55b86e66-20210421-132208]
at sailpoint.fulltext.Builder.refreshIndex(Builder.java:212) [identityiq.jar:8.1 Build dfd55b86e66-20210421-132208]
at sailpoint.fulltext.Builder.refreshAll(Builder.java:170) [identityiq.jar:8.1 Build dfd55b86e66-20210421-132208]
at sailpoint.api.FullTextifier.refreshAll(FullTextifier.java:199) [identityiq.jar:8.1 Build dfd55b86e66-20210421-132208]
at sailpoint.server.FullTextService.refresh(FullTextService.java:186) [identityiq.jar:8.1 Build dfd55b86e66-20210421-132208]
at sailpoint.server.FullTextService.execute(FullTextService.java:141) [identityiq.jar:8.1 Build dfd55b86e66-20210421-132208]
at sailpoint.server.Servicer.execute(Servicer.java:981) [identityiq.jar:8.1 Build dfd55b86e66-20210421-132208]
at sailpoint.server.Servicer.processServices(Servicer.java:932) [identityiq.jar:8.1 Build dfd55b86e66-20210421-132208]
at sailpoint.server.Servicer.run(Servicer.java:677) [identityiq.jar:8.1 Build dfd55b86e66-20210421-132208]
and other unexpected events, such as duplicate copies of the same Task running at once on the same server, which can result in all kinds of errors, including LazyInitializationException or random data corruption. You might also see performance issues, as tomcat will be using twice as much memory as normally expected.
In thread dumps (from /debug/threads.jsf) you will have multiple copies of various threads such as the RequestProcessor and the HeartbeatThread:
| 27 |
HeartbeatThread |
10 |
TIMED_WAITING |
| |
| java.lang.Thread.sleep(Native Method) |
| sailpoint.server.HeartbeatService$HeartbeatThread.sleep(HeartbeatService.java:575) |
| sailpoint.server.HeartbeatService$HeartbeatThread.run(HeartbeatService.java:548) |
|
...
| 178 |
HeartbeatThread |
10 |
TIMED_WAITING |
| |
| java.lang.Thread.sleep(Native Method) |
| sailpoint.server.HeartbeatService$HeartbeatThread.sleep(HeartbeatService.java:575) |
| sailpoint.server.HeartbeatService$HeartbeatThread.run(HeartbeatService.java:548) |
|
|
These duplicate HeartbeatThreads are the cause of the early heartbeat warnings.
Diagnosis
There are two instances of IdentityIQ running on the same appserver. On tomcat, very often this is due to an attempt to change the web context of IdentityIQ from "/identityiq" to just "/". If this is done by adding a <Context> in the server.xml, for example:
<Host name="localhost" appBase="webapps" unpackWARs="true" autoDeploy="true">
<Context path="" docBase="identityiq">
</Context>
then instead of just changing the context you are actually creating a second context, with duplicate threads.
On other appservers, it could be due to having two copies of the same identityiq.war deployed.
Note: You may also get early heartbeat warnings if you have IIQ installed on multiple server and the server times are not in sync. If that is the case, simply make sure the server times get synchronised. In this case, you will likely also see warnings about the heartbeat being missed: "Servers missed a heartbeat: <list of servers that missed a heartbeat>".
Solution
There are a few ways to correct this, depending on your configuration:
- Remove one of the duplicate war files/folders, if you have more than one deployed.
- If you are using a <Context> in Tomcat, remove the <Context> from the server.xml. If you need the web context path to be '/' instead, rename the {tomcat}/webapps/identityiq directory to {tomcat}/webapps/ROOT. For Tomcat, ROOT is a special name, indicating that the context path needs to be '/'.
Alternatively, you can move the identityiq folder outside of the {tomcat}/webapps folder and change the docBase to that path:
<Host name="localhost" appBase="webapps" unpackWARs="true" autoDeploy="true">
<Context path="" docBase="/path/outside/tomcat/identityiq">
</Context>
Moving the {tomcat}/webapps/identityiq folder outside of the {tomcat}/webapps folder will prevent the identityiq folder itself from being deployed as a separate instance.
Please consult with your appserver admin for the best solution for your environment.
