Troubleshooting Information Centric Encryption (ICE) 102 On-Premise Key Store


Article ID: 171098


Updated On:


Information Centric Encryption


Troubleshooting Information Centric Encryption (ICE) 102 - On-Premise Key Store.


ICE 102 - On-Premise Key Store


Check individual Key Store connections count and ICE Cloud console for amount of connected Key Stores.

  • Key Store count reflects how many KSBs it is connected to
  • ICE Console displays connected Key Stores

All Key Stores on ICE Console should have green checkmark if keys are properly synced (no key conflict). Individual Key Stores would not display any warning in case of key conflict.

Key migration/rotation may take up to 24 hours to reach clients

Keys Store Logs includes the content of Audit Logs

  • kss.log – Key Store Service logs
  • ksm.log – Key Store Manager logs
  • kscli.log – Administrator changes from CLI

Troubleshooting in ksm.log

[INFO ] 2018-01-29 21:13:36.225 [http-nio-8080-exec-10] audit - [administrator] logged in.
[DEBUG] 2018-01-29 21:13:41.257 [http-nio-8080-exec-5] RequestInterceptor - [administrator] POST URI [/KSM/v1/deleteAdmin].
[INFO ] 2018-01-29 21:13:41.272 [http-nio-8080-exec-5] audit - [administrator] removed administrator 'testUser1'.
[DEBUG] 2018-01-29 21:14:31.776 [http-nio-8080-exec-8] KssHealthProperties - KSS Health connection status: [4 of 4]
[DEBUG] 2018-01-29 21:14:41.302 [http-nio-8080-exec-1] RequestInterceptor - [administrator] POST URI [/KSM/v1/name].
[INFO ] 2018-01-29 21:14:41.305 [http-nio-8080-exec-1] IceCloudProperties - Flushing Ice Cloud properties to file.
[INFO ] 2018-01-29 21:14:41.305 [http-nio-8080-exec-1] IceCloudProperties - Ice Cloud Properties: domainId [ca10ed2e3bb13698a850dc], customerId [02c2946594e318ac2ad3c7] elbDnsName[] username [a10b4476-5952-44ad-ae5a-13a0925fe7a4] boxName []
[INFO ] 2018-01-29 21:14:41.306 [http-nio-8080-exec-1] audit - [administrator] successfully changed the name of the key store to ''.

Some exceptions are normal and can be ignored:
[DEBUG] 2018-01-29 21:13:24.889 [http-nio-8080-exec-3] AuthService - UDPException on login: Admin file changed by CLI.
[DEBUG] 2018-01-26 22:02:03.470 [http-nio-8080-exec-9] KeyStoreController - No keys are present in the keystore
java.lang.IllegalStateException: No key store file found.

Bad KSB host, invalid password, communication error during setup may also trigger exceptions that could be useful in troubleshooting.

Bad password example:
[DEBUG] 2018-02-07 18:20:11.413 [http-nio-8080-exec-8] RequestInterceptor - [administrator] POST URI [/KSM/v1/settings].
[DEBUG] 2018-02-07 18:20:11.546 [http-nio-8080-exec-8] KsmSslConfiguration - SslEngineConfigurator successfully created, truststore /encrypted-data/symantec/udp/etc/shared/kstruststore.jks
[INFO ] 2018-02-07 18:20:12.400 [Grizzly(1)] KsmEndpoint - [onOpen] reqId: a3277c5e-0dc9-4fd7-aebc-7adfd1f7be43, sessionId: 8f097ee7-e198-4858-b7c6-7a320effa066. Sending auth credentials.
[INFO ] 2018-02-07 18:20:12.661 [Grizzly(2)] KsmMessageHandler - [onMessage] regId: a3277c5e-0dc9-4fd7-aebc-7adfd1f7be43, sessionId: 8f097ee7-e198-4858-b7c6-7a320effa066, message: {"msgType":"AUTH_RSP","ksbId":"a1781eb9-e077-4de7-b577-5ef7529cefda","reqId":"a3277c5e-0dc9-4fd7-aebc-7adfd1f7be43","ptlVer":"0.0.0","success":false,"errMsg":"Not authenticated."}
[DEBUG] 2018-02-07 18:20:12.666 [Grizzly(2)] KsmMessageHandler - [onMessage] regId: a3277c5e-0dc9-4fd7-aebc-7adfd1f7be43, sessionId: 8f097ee7-e198-4858-b7c6-7a320effa066. Closing session.
[DEBUG] 2018-02-07 18:20:12.667 [Grizzly(2)] KsmEndpoint - [onClose] reqId: a3277c5e-0dc9-4fd7-aebc-7adfd1f7be43, sessionId: 8f097ee7-e198-4858-b7c6-7a320effa066, Reason: CloseReason: code [1000], reason [null]
[DEBUG] 2018-02-07 18:20:12.666 [http-nio-8080-exec-8] KSMControllerAdvice - caught an exception: Cannot validate credentials.

Bad host example:
[DEBUG] 2018-02-07 18:25:29.880 [http-nio-8080-exec-5] RequestInterceptor - [administrator] POST URI [/KSM/v1/settings].
[DEBUG] 2018-02-07 18:25:30.017 [http-nio-8080-exec-5] KsmSslConfiguration - SslEngineConfigurator successfully created, truststore /encrypted-data/symantec/udp/etc/shared/kstruststore.jks
[ERROR] 2018-02-07 18:25:30.483 [http-nio-8080-exec-5] KsmWebSocketClient - [validate] reqId: afbc4355-0db4-4d11-8141-202d33f5d342. Connection failure.
[DEBUG] 2018-02-07 18:25:30.483 [http-nio-8080-exec-5] KsmWebSocketClient - [validate] reqId: afbc4355-0db4-4d11-8141-202d33f5d342. Exception:
javax.websocket.DeploymentException: Connection failed.
Caused by: java.nio.channels.UnresolvedAddressException

Suspicious exception example caused by manual altering of post request:
[DEBUG] 2018-01-29 21:31:03.541 [http-nio-8080-exec-4] RequestInterceptor - [administrator] POST URI [/KSM/v1/name].
[DEBUG] 2018-01-29 21:31:03.575 [http-nio-8080-exec-4] KSMControllerAdvice - caught an exception: Argument validation error.

External scanning tools or attacks may also generate exceptions.

Troubleshooting (kscli.log)

kscli.log is for activity performed by command “ice-onprem”
[INFO ] 2018-01-29 20:52:52.027 [Did-6-Worker-5] InputValidator - username: Must be between 8 and 64 characters.
[DEBUG] 2018-01-29 20:52:52.027 [Did-6-Worker-5] InputValidator - password: Must contain at least one upper-case character, one lower-case character, one number, and one special character.
[DEBUG] 2018-01-29 21:00:58.724 [Did-6-Worker-5] InputValidator - Passwords do not match.
[INFO ] 2018-01-29 21:02:00.733 [Did-6-Worker-5] AdminService - Request to add a new keystore admin - testUser1
[INFO ] 2018-01-29 21:02:29.880 [Did-6-Worker-5] AdminService - Request to reset the password for the keystore admin - testUser1

Troubleshooting kss.log (Key Store Service)

  • KSS troubleshooting is done by analyzing the log file.
  • Note that KSS is only part of the bigger system, so the root cause of the observed problem may lay somewhere else. However, it is important to make sure that KSS works correctly.
  • KSS Log can indicate Authentication issues with the External Service Credentials used to connect to the ICE Console

Example of External Service Authentication Failure:
[INFO ] 2019-09-20 00:28:14.378 [main] KssConnector - <<< Begin Az 1: connected 0 Ksb(s), maxAttempts 2, uri wss://
[INFO ] 2019-09-20 00:28:14.709 [Grizzly(1)] KssEndpoint - onOpen websocket session: thrId 6545, ssnId 88f93505-c7b0-4874-9f10-2ff4544dbc8c
[INFO ] 2019-09-20 00:28:14.709 [Grizzly(1)] KssEndpoint - <-- AuthRequest: reqId 4c32406d-46a3-49a2-b2d0-eaf35d165c8c, boxId 12345678-da82-42af-bbdb-328cb0f49875, boxName ICE KSM #1
[INFO ] 2019-09-20 00:28:14.849 [Grizzly(2)] KssMsgHandler - --> AuthResponse: reqId 4c32406d-46a3-49a2-b2d0-eaf35d165c8c, ksbId 87654321-e732-43a0-bbbb-192839cba832, success false, ksbCount 0, azCount 0, errMsg Not authenticated.
[ERROR] 2019-09-20 00:28:14.849 [main] KssConnector - *** Authentication denied: Not authenticated.

Successfully provisioned (by setting up or restoring from back up) Key Store does not establish required number of connections with Ice Cloud.

Check that:

  • KSS was properly initialized and was running before provisioning.
  • Relevant provisioning KSM event were detected and successfully processed.
  • KSS started connection attempts.
  • Websocket session is opened, authentication request is sent to ICE Cloud.
  • Corresponding authentication response is received.
  • Authentication is successful and valid number of deployed KSB instances and AWS availability zones is reported by Ice Cloud.
  • Examine error messages to understand the reason for connection failure.   

KSS worked correctly after provisioning, then connections were lost and could not be re-established.

Do the following:

  • Find the last connection status message stating that all KSB(s) are connected.
  • Look for following “close session” messages to understand how sessions were closed.
  • Examine messages related to failing connection attempts.
  • If there is persistent authentication problem that could possibly be caused by customer changing service password on ICECloud console but not on the Key Store, change password on the Key Store.     

Verify that KSS receives and successfully processes unlock File Encryption Key (FEK) requests

  • Locate last unlock FEK statistics message and see how many valid unlock requests were received, processed and failed since KSS started.
  • You can calculate statistics for period of time by subtracting corresponding values in two messages.
  • If statistics message shows failed requests, look for error messages relevant to unlock FEK request and identify the reason of failure.