Windows MID Server hangs for minutes during startup - StartupSequencer falling back to slow ThreadedSeedGenerator for encryptions keys, instead of using CryptoAPI (/dev/urandom) - Support and Troubleshooting

Windows MID Server hangs for minutes during startup - StartupSequencer falling back to slow ThreadedSeedGenerator for encryptions keys, instead of using CryptoAPI (/dev/urandom) Issue On startup of the MID Server, there are long delays with no logging seen in the agent log during that time.

For example:

Note: The DEBUG and TRACE lines are only seen when mid.log.level=debug (or trace)

03/25/22 17:00:33 (626) StartupSequencer Getting instance ACLs for table: ecc_agent 03/25/22 17:00:33 (626) StartupSequencer DEBUG: Getting key pair from cache with handle: DefaultSecurityKeyPairHandle 03/25/22 17:00:33 (641) StartupSequencer TRACE: unsecuredParameterValue | decodedText: 03/25/22 17:00:33 (860) StartupSequencer DEBUG: Event: RGRPerfMetricEvent 03/25/22 17:00:33 (876) StartupSequencer DEBUG: Getting key pair from cache with handle: DefaultSecurityKeyPairHandle 03/25/22 17:00:33 (876) StartupSequencer DEBUG: Getting key pair from cache with handle: DefaultSecurityKeyPairHandle ---long gap--- 03/25/22 17:32:45 (200) StartupSequencer DEBUG: Getting key pair from cache with handle: DefaultSecurityKeyPairHandle 03/25/22 17:32:45 (200) StartupSequencer TRACE: unsecuredParameterValue | decodedText: 03/25/22 17:32:45 (278) StartupSequencer DEBUG: MIDSecPolicy: calculating security Policy to be applied on .service-now.com 03/25/22 17:32:45 (278) StartupSequencer DEBUG: MIDSecPolicy: trying to resolve a security policy for an IP [ .service-now.com] 03/25/22 17:32:45 (278) StartupSequencer DEBUG: MIDSecPolicy: Introducing the resolved cert policy to the fast cache! 03/25/22 17:32:45 (278) StartupSequencer DEBUG: MIDSecPolicy: Security policy selected -> null [SYSTEM_DEFAULTS] for target -> .service-now.com 03/25/22 17:32:45 (278) StartupSequencer DEBUG: MIDSecPolicy: hostname verification for host[ .service-now.com] is true 03/25/22 17:32:45 (278) StartupSequencer DEBUG: MIDSecPolicy: calculating security Policy to be applied on .service-now.com 03/25/22 17:32:45 (278) StartupSequencer DEBUG: MIDSecPolicy: returning a security policy from the fast cache! 03/25/22 17:32:45 (278) StartupSequencer DEBUG: MIDSecPolicy: Certificate revocation check for host[ .service-now.com] is true 03/25/22 17:32:45 (684) StartupSequencer DEBUG: Getting key pair from cache with handle: DefaultSecurityKeyPairHandle 03/25/22 17:32:45 (684) StartupSequencer TRACE: unsecuredParameterValue | decodedText: ---long gap--- 03/25/22 17:44:06 (643) StartupSequencer Updated public key, new certificate: ...

Release This has been seen to occur dependent on the MID Server Windows Service logon on User (runs as user), where a Local user is fine, but a Domani user has this issue.

Cause You need a thread dump to confirm what's going on at those times. As the MID Server is not up yet, you can't use the Grab Logs link on the mid server form to get a Thread call stack dump, but you can do this from the command line using Java SDK's "jstack" tool. https://docs.oracle.com/javase/7/docs/technotes/tools/share/jstack.html

That would show you that you have the StartupSequencer thread stuck waiting for "sun.security.provider.SeedGenerator$ThreadedSeedGenerator", which we should not be using in the first place.

"StartupSequencer" #145 daemon prio=5 os_prio=0 cpu=671.88ms elapsed=38.69s tid=0x0000019d309b6800 nid=0xbec in Object.wait() [0x00000095e9dfd000] java.lang.Thread.State: WAITING (on object monitor) at java.lang.Object.wait(java.base@11.0.9.1-sncmid1/Native Method) - waiting on (a sun.security.provider.SeedGenerator$ThreadedSeedGenerator) at java.lang.Object.wait(java.base@11.0.9.1-sncmid1/Object.java:328) at sun.security.provider.SeedGenerator$ThreadedSeedGenerator.getSeedByte(java.base@11.0.9.1-sncmid1/SeedGenerator.java:404) - waiting to re-lock in wait() (a sun.security.provider.SeedGenerator$ThreadedSeedGenerator) at sun.security.provider.SeedGenerator$ThreadedSeedGenerator.getSeedBytes(java.base@11.0.9.1-sncmid1/SeedGenerator.java:393) at sun.security.provider. SeedGenerator.generateSeed (java.base@11.0.9.1-sncmid1/SeedGenerator.java:144) at sun.security.provider.AbstractDrbg.engineGenerateSeed(java.base@11.0.9.1-sncmid1/AbstractDrbg.java:456) at sun.security.provider.DRBG.engineGenerateSeed(java.base@11.0.9.1-sncmid1/DRBG.java:238) at java.security. SecureRandom.generateSeed (java.base@11.0.9.1-sncmid1/SecureRandom.java:857) at org.bouncycastle.crypto.util.BasicEntropySourceProvider$1.getEntropy(Unknown Source) at org.bouncycastle.crypto.fips. ContinuousTestingEntropySource.getEntropy (Unknown Source) - locked (a org.bouncycastle.crypto.fips.ContinuousTestingEntropySource) at org.bouncycastle.crypto.fips.HashSP800DRBG.getEntropy(Unknown Source) at org.bouncycastle.crypto.fips.HashSP800DRBG.reseed(Unknown Source) at org.bouncycastle.crypto.fips.HashSP800DRBG.generate(Unknown Source) at org.bouncycastle.crypto.fips.ContinuousTestingPseudoRNG.generate(Unknown Source) - locked (a org.bouncycastle.crypto.fips.ContinuousTestingPseudoRNG) at org.bouncycastle.crypto.fips.DRBGPseudoRandom.generate(Unknown Source) - locked (a org.bouncycastle.crypto.fips.DRBGPseudoRandom) at org.bouncycastle.crypto.fips.FipsSecureRandom$RandomSpi.engineNextBytes(Unknown Source) - locked (a org.bouncycastle.crypto.fips.DRBGPseudoRandom) at java.security.SecureRandom.nextBytes(java.base@11.0.9.1-sncmid1/SecureRandom.java:754) - locked (a org.bouncycastle.crypto.fips.FipsSecureRandom) at java.math.BigInteger.randomBits(java.base@11.0.9.1-sncmid1/BigInteger.java:700) at java.math.BigInteger. (java.base@11.0.9.1-sncmid1/BigInteger.java:689) at java.math.BigInteger.passesMillerRabin(java.base@11.0.9.1-sncmid1/BigInteger.java:1098) at java.math.BigInteger.primeToCertainty(java.base@11.0.9.1-sncmid1/BigInteger.java:958) at java.math.BitSieve.retrieve(java.base@11.0.9.1-sncmid1/BitSieve.java:203) at java.math.BigInteger.largePrime(java.base@11.0.9.1-sncmid1/BigInteger.java:827) at java.math.BigInteger. (java.base@11.0.9.1-sncmid1/BigInteger.java:733) at org.bouncycastle.crypto.fips.RsaKeyPairGenerator.chooseRandomPrime(Unknown Source) at org.bouncycastle.crypto.fips.RsaKeyPairGenerator.generateKeyPair(Unknown Source) at org.bouncycastle.crypto.fips.FipsRSA$KeyPairGenerator.generateKeyPair(Unknown Source) at org.bouncycastle.jcajce.provider.ProvRSA$KeyPairGenerator.generateKeyPair(Unknown Source) at com.snc.commons.security.MIDKeyPair.generate (MIDKeyPair.java:41) at com.service_now.mid.keypairs.provider.standard.StandardKeyPairsProvider.generateKeyPair (StandardKeyPairsProvider.java:54) at com.service_now.mid.Instance.ensurePublicKey(Instance.java:1153) at com.service_now.mid.Instance.ensureUniquelyNamedAgentRecord(Instance.java:246) at com.service_now.mid.Instance.ensureAgentRecord(Instance.java:202) at com.service_now.mid.services. StartupSequencer.ensureUniqueAgentRecordFromInstance (StartupSequencer.java:296) at com.service_now.mid.services.StartupSequencer.testsSucceeded(StartupSequencer.java:156) at com.service_now.mid.services.StartupSequencer.startupSequencerRunnable(StartupSequencer.java:731) at com.service_now.mid.services.StartupSequencer$$Lambda$411/0x0000000100680040.run(Unknown Source) at java.lang.Thread.run(java.base@11.0.9.1-sncmid1/Thread.java:834) In general that would suggest a delay generating a seed value for an encryption key, from a pseudo-random number.

The java.security.SecureRandom class provides a cryptographically strong random number generator (RNG). The sun.security.provider class represents a "provider" for the Java Security API, and provides services including Algorithms (such as DSA, RSA, MD5 or SHA-1), and Key generation, conversion, and management facilities (such as for algorithm-specific keys). You can increase logging for this particular engine and provider by adding this extra property to the end of the agent\conf\wrapper-override.conf file:

wrapper.java.additional.5=-Djava.security.debug="provider,engine=SecureRandom" The wrapper.log may then give additional information such as this, the reason for the delay is that the threaded seed generator is very very slow :

2022/05/25 12:23:02 | provider: Failed to use operating system seed generator: java.io.IOException: Required native CryptoAPI features not available on this machine 2022/05/25 12:23:02 | provider: Using default threaded seed generator What you would expect to see would be this, meaning it's getting the random numbers from the Windows OS, which may even be using special hardware for the purpose to speed things up:

2022/06/02 09:51:36 | provider: Using operating system seed generatorfile:/dev/urandom

Resolution Under investigation at the time of writing.

Related Links In theory Linux MID Server installs could also have a similar issue. In that case, the available Entropy of the server should be investigated.