Interpreting AWS CloudHSM audit logs
The events in the HSM audit logs have standard fields. Some event types have additional fields that capture useful information about the event. For example, user login and user management events include the user name and user type of the user. Key management commands include the key handle.
Several of the fields provide particularly important information. The Opcode
identifies the management command that is being recorded. The Sequence No
identifies an event in the log stream and indicates the order in which it was recorded.
For example, the following example event is the second event (Sequence No:
0x1) in the log stream for an HSM. It shows the HSM generating a password encryption
key, which is part of its startup routine.
Time: 12/19/17 21:01:17.140812, usecs:1513717277140812 Sequence No : 0x1 Reboot counter : 0xe8 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_GEN_PSWD_ENC_KEY (0x1d) Session Handle : 0x1004001 Response : 0:HSM Return: SUCCESS Log type : MINIMAL_LOG_ENTRY (0)
The following fields are common to every AWS CloudHSM event in the audit log.
- Time
-
The time that the event occurred in the UTC time zone. The time is displayed as a human-readable time and Unix time in microseconds.
- Reboot counter
-
A 32-bit persistent ordinal counter that is incremented when the HSM hardware is rebooted.
All events in a log stream have the same reboot counter value. However, the reboot counter might not be unique to a log stream, as it can differ across different HSM instances in the same cluster.
- Sequence No
-
A 64-bit ordinal counter that is incremented for each log event. The first event in each log stream has a sequence number of 0x0. There should be no gaps in the
Sequence Novalues. The sequence number is unique only within a log stream. - Command type
-
A hexadecimal value that represents the category of the command. Commands in the AWS CloudHSM log streams have a command type of
CN_MGMT_CMD(0x0) orCN_CERT_AUTH_CMD(0x9). - Opcode
-
Identifies the management command that was executed. For a list of
Opcodevalues in the AWS CloudHSM audit logs, see AWS CloudHSM audit log reference. - Session handle
-
Identifies the session in which the command was run and the event was logged.
- Response
-
Records the response to the management command. You can search the
Responsefield forSUCCESSandERRORvalues. - Log type
-
Indicates the log type of the AWS CloudHSM log that recorded the command.
-
MINIMAL_LOG_ENTRY (0) -
MGMT_KEY_DETAILS_LOG (1) -
MGMT_USER_DETAILS_LOG (2) -
GENERIC_LOG
-
Examples of audit log events
The events in a log stream record the history of the HSM from its creation to deletion.
You can use the log to review the lifecycle of your HSMs and gain insight into its operation.
When you interpret the events, note the Opcode, which indicates the management
command or action, and the Sequence No, which indicates the order of events.
Topics
Example: Initialize the first HSM in a cluster
The audit log stream for the first HSM in each cluster differs significantly from the log streams of other HSMs in the cluster. The audit log for the first HSM in each cluster records its creation and initialization. The logs of additional HSMs in the cluster, which are generated from backups, begin with a login event.
Important
The following initialization entries will not appear in the CloudWatch logs of clusters initialized before the release of the CloudHSM audit logging feature (August 30, 2018). For more information, see Document History.
The following example events appear in the log stream for the first HSM in a cluster.
The first event in the log — the one with Sequence No 0x0 —
represents the command to initialize the HSM (CN_INIT_TOKEN). The response
indicates that the command was successful (Response : 0: HSM Return:
SUCCESS).
Time: 12/19/17 21:01:16.962174, usecs:1513717276962174 Sequence No : 0x0 Reboot counter : 0xe8 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_INIT_TOKEN (0x1) Session Handle : 0x1004001 Response : 0:HSM Return: SUCCESS Log type : MINIMAL_LOG_ENTRY (0)
The second event in this example log stream (Sequence No 0x1) records the
command to create the password encryption key that the HSM uses
(CN_GEN_PSWD_ENC_KEY).
This is a typical startup sequence for the first HSM in each cluster. Because subsequent HSMs in the same cluster are clones of the first one, they use the same password encryption key.
Time: 12/19/17 21:01:17.140812, usecs:1513717277140812 Sequence No : 0x1 Reboot counter : 0xe8 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_GEN_PSWD_ENC_KEY (0x1d) Session Handle : 0x1004001 Response : 0:HSM Return: SUCCESS Log type : MINIMAL_LOG_ENTRY (0)
The third event in this example log stream (Sequence No 0x2) is the
creation of the appliance user (AU), which is the
AWS CloudHSM service. Events that involve HSM users include extra fields for the user name and user
type.
Time: 12/19/17 21:01:17.174902, usecs:1513717277174902 Sequence No : 0x2 Reboot counter : 0xe8 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_CREATE_APPLIANCE_USER (0xfc) Session Handle : 0x1004001 Response : 0:HSM Return: SUCCESS Log type : MGMT_USER_DETAILS_LOG (2) User Name : app_user User Type : CN_APPLIANCE_USER (5)
The fourth event in this example log stream (Sequence No 0x3) records the
CN_INIT_DONE event, which completes the initialization of the HSM.
Time: 12/19/17 21:01:17.298914, usecs:1513717277298914 Sequence No : 0x3 Reboot counter : 0xe8 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_INIT_DONE (0x95) Session Handle : 0x1004001 Response : 0:HSM Return: SUCCESS Log type : MINIMAL_LOG_ENTRY (0)
You can follow the remaining events in the startup sequence. These events might include several login and logout events, and the generation of the key encryption key (KEK). The following event records the command that changes the password of the precrypto officer (PRECO). This command activates the cluster.
Time: 12/13/17 23:04:33.846554, usecs:1513206273846554 Sequence No: 0x1d Reboot counter: 0xe8 Command Type(hex): CN_MGMT_CMD (0x0) Opcode: CN_CHANGE_PSWD (0x9) Session Handle: 0x2010003 Response: 0:HSM Return: SUCCESS Log type: MGMT_USER_DETAILS_LOG (2) User Name: admin User Type: CN_CRYPTO_PRE_OFFICER (6)
Login and logout events
When interpreting your audit log, note events that record users logging and in and out of the HSM. These events help you to determine which user is responsible for management commands that appear in sequence between the login and logout commands.
For example, this log entry records a login by a crypto officer named
admin. The sequence number, 0x0, indicates that this is the first
event in this log stream.
When a user logs into an HSM, the other HSMs in the cluster also record a login event for the user. You can find the corresponding login events in the log streams of other HSMs in the cluster shortly after the initial login event.
Time: 01/16/18 01:48:49.824999, usecs:1516067329824999 Sequence No : 0x0 Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_LOGIN (0xd) Session Handle : 0x7014006 Response : 0:HSM Return: SUCCESS Log type : MGMT_USER_DETAILS_LOG (2) User Name : admin User Type : CN_CRYPTO_OFFICER (2)
The following example event records the admin crypto officer logging out.
The sequence number, 0x2, indicates that this is the third event in the log
stream.
If the logged in user closes the session without logging out, the log stream includes an
CN_APP_FINALIZE or close session event (CN_SESSION_CLOSE),
instead of a CN_LOGOUT event. Unlike the login event, this logout event
typically is recorded only by the HSM that executes the command.
Time: 01/16/18 01:49:55.993404, usecs:1516067395993404 Sequence No : 0x2 Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_LOGOUT (0xe) Session Handle : 0x7014000 Response : 0:HSM Return: SUCCESS Log type : MGMT_USER_DETAILS_LOG (2) User Name : admin User Type : CN_CRYPTO_OFFICER (2)
If a login attempt fails because the user name is invalid, the HSM records a
CN_LOGIN event with the user name and type provided in the login command. The
response displays error message 157, which explains that the user name does not
exist.
Time: 01/24/18 17:41:39.037255, usecs:1516815699037255 Sequence No : 0x4 Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_LOGIN (0xd) Session Handle : 0xc008002 Response : 157:HSM Error: user isn't initialized or user with this name doesn't exist Log type : MGMT_USER_DETAILS_LOG (2) User Name : ExampleUser User Type : CN_CRYPTO_USER (1)
If a login attempt fails because the password is invalid, the HSM records a
CN_LOGIN event with the user name and type provided in the login command. The
response displays the error message with the RET_USER_LOGIN_FAILURE error
code.
Time: 01/24/18 17:44:25.013218, usecs:1516815865013218 Sequence No : 0x5 Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_LOGIN (0xd) Session Handle : 0xc008002 Response : 163:HSM Error: RET_USER_LOGIN_FAILURE Log type : MGMT_USER_DETAILS_LOG (2) User Name : testuser User Type : CN_CRYPTO_USER (1)
Example: Create and delete users
This example shows the log events that are recorded when a crypto officer (CO) creates and deletes users.
The first event records a CO, admin, logging into the HSM. The sequence
number of 0x0 indicates that this is the first event in the log stream. The
name and type of the user who logged in are included in the event.
Time: 01/16/18 01:48:49.824999, usecs:1516067329824999 Sequence No : 0x0 Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_LOGIN (0xd) Session Handle : 0x7014006 Response : 0:HSM Return: SUCCESS Log type : MGMT_USER_DETAILS_LOG (2) User Name : admin User Type : CN_CRYPTO_OFFICER (2)
The next event in the log stream (sequence 0x1) records the CO creating a
new crypto user (CU). The name and type of the new user are included in the event.
Time: 01/16/18 01:49:39.437708, usecs:1516067379437708 Sequence No : 0x1 Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_CREATE_USER (0x3) Session Handle : 0x7014006 Response : 0:HSM Return: SUCCESS Log type : MGMT_USER_DETAILS_LOG (2) User Name : bob User Type : CN_CRYPTO_USER (1)
Then, the CO creates another crypto officer, alice. The sequence number
indicates that this action followed the previous one with no intervening actions.
Time: 01/16/18 01:49:55.993404, usecs:1516067395993404 Sequence No : 0x2 Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_CREATE_CO (0x4) Session Handle : 0x7014007 Response : 0:HSM Return: SUCCESS Log type : MGMT_USER_DETAILS_LOG (2) User Name : alice User Type : CN_CRYPTO_OFFICER (2)
Later, the CO named admin logs in and deletes the crypto officer named
alice. The HSM records a CN_DELETE_USER event. The name and type
of the deleted user are included in the event.
Time: 01/23/18 19:58:23.451420, usecs:1516737503451420 Sequence No : 0xb Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_DELETE_USER (0xa1) Session Handle : 0x7014007 Response : 0:HSM Return: SUCCESS Log type : MGMT_USER_DETAILS_LOG (2) User Name : alice User Type : CN_CRYPTO_OFFICER (2)
Example: Create and delete a key pair
This example shows the events that are recorded in an HSM audit log when you create and delete a key pair.
The following event records the crypto user (CU) named crypto_user logging
in to the HSM.
Time: 12/13/17 23:09:04.648952, usecs:1513206544648952 Sequence No: 0x28 Reboot counter: 0xe8 Command Type(hex): CN_MGMT_CMD (0x0) Opcode: CN_LOGIN (0xd) Session Handle: 0x2014005 Response: 0:HSM Return: SUCCESS Log type: MGMT_USER_DETAILS_LOG (2) User Name: crypto_user User Type: CN_CRYPTO_USER (1)
Next, the CU generates a key pair (CN_GENERATE_KEY_PAIR). The private key
has key handle 131079. The public key has key handle 131078.
Time: 12/13/17 23:09:04.761594, usecs:1513206544761594 Sequence No: 0x29 Reboot counter: 0xe8 Command Type(hex): CN_MGMT_CMD (0x0) Opcode: CN_GENERATE_KEY_PAIR (0x19) Session Handle: 0x2014004 Response: 0:HSM Return: SUCCESS Log type: MGMT_KEY_DETAILS_LOG (1) Priv/Secret Key Handle: 131079 Public Key Handle: 131078
The CU immediately deletes the key pair. A CN_DESTROY_OBJECT event records the deletion of the public key (131078).
Time: 12/13/17 23:09:04.813977, usecs:1513206544813977 Sequence No: 0x2a Reboot counter: 0xe8 Command Type(hex): CN_MGMT_CMD (0x0) Opcode: CN_DESTROY_OBJECT (0x11) Session Handle: 0x2014004 Response: 0:HSM Return: SUCCESS Log type: MGMT_KEY_DETAILS_LOG (1) Priv/Secret Key Handle: 131078 Public Key Handle: 0
Then, a second CN_DESTROY_OBJECT event records the deletion of the private
key (131079).
Time: 12/13/17 23:09:04.815530, usecs:1513206544815530 Sequence No: 0x2b Reboot counter: 0xe8 Command Type(hex): CN_MGMT_CMD (0x0) Opcode: CN_DESTROY_OBJECT (0x11) Session Handle: 0x2014004 Response: 0:HSM Return: SUCCESS Log type: MGMT_KEY_DETAILS_LOG (1) Priv/Secret Key Handle: 131079 Public Key Handle: 0
Finally, the CU logs out.
Time: 12/13/17 23:09:04.817222, usecs:1513206544817222 Sequence No: 0x2c Reboot counter: 0xe8 Command Type(hex): CN_MGMT_CMD (0x0) Opcode: CN_LOGOUT (0xe) Session Handle: 0x2014004 Response: 0:HSM Return: SUCCESS Log type: MGMT_USER_DETAILS_LOG (2) User Name: crypto_user User Type: CN_CRYPTO_USER (1)
Example: Generate and synchronize a key
This example shows the effect of creating a key in a cluster with multiple HSMs. The key is generated on one HSM, extracted from the HSM as a masked object, and inserted in the other HSMs as a masked object.
Note
The client tools might fail to synchronize the key. Or the command might include the min_srv parameter, which synchronizes the key only to the specified number of HSMs. In either case, the AWS CloudHSM service synchronizes the key to the other HSMs in the cluster. Because the HSMs record only client-side management commands in their logs, the server-side synchronization is not recorded in the HSM log.
First consider the log stream of the HSM that receives and executes the commands. The
log stream is named for HSM ID, hsm-abcde123456, but the HSM ID does not appear
in the log events.
First, the testuser crypto user (CU) logs in to the
hsm-abcde123456 HSM.
Time: 01/24/18 00:39:23.172777, usecs:1516754363172777 Sequence No : 0x0 Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_LOGIN (0xd) Session Handle : 0xc008002 Response : 0:HSM Return: SUCCESS Log type : MGMT_USER_DETAILS_LOG (2) User Name : testuser User Type : CN_CRYPTO_USER (1)
The CU runs an exSymKey command to
generate a symmetric key. The hsm-abcde123456 HSM generates a symmetric key
with a key handle of 262152. The HSM records a CN_GENERATE_KEY
event in its log.
Time: 01/24/18 00:39:30.328334, usecs:1516754370328334 Sequence No : 0x1 Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_GENERATE_KEY (0x17) Session Handle : 0xc008004 Response : 0:HSM Return: SUCCESS Log type : MGMT_KEY_DETAILS_LOG (1) Priv/Secret Key Handle : 262152 Public Key Handle : 0
The next event in the log stream for hsm-abcde123456 records the first step
in the key synchronization process. The new key (key handle 262152) is
extracted from the HSM as a masked object.
Time: 01/24/18 00:39:30.330956, usecs:1516754370330956 Sequence No : 0x2 Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_EXTRACT_MASKED_OBJECT_USER (0xf0) Session Handle : 0xc008004 Response : 0:HSM Return: SUCCESS Log type : MGMT_KEY_DETAILS_LOG (1) Priv/Secret Key Handle : 262152 Public Key Handle : 0
Now consider the log stream for HSM hsm-zyxwv987654, another HSM in the
same cluster. This log stream also includes a login event for the testuser CU.
The time value shows that occurs shortly after the user logs in to the
hsm-abcde123456 HSM.
Time: 01/24/18 00:39:23.199740, usecs:1516754363199740 Sequence No : 0xd Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_LOGIN (0xd) Session Handle : 0x7004004 Response : 0:HSM Return: SUCCESS Log type : MGMT_USER_DETAILS_LOG (2) User Name : testuser User Type : CN_CRYPTO_USER (1)
This log stream for this HSM does not have a CN_GENERATE_KEY event. But it
does have an event that records synchronization of the key to this HSM. The
CN_INSERT_MASKED_OBJECT_USER event records the receipt of key
262152 as a masked object. Now key 262152 exists on both HSMs in
the cluster.
Time: 01/24/18 00:39:30.408950, usecs:1516754370408950 Sequence No : 0xe Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_INSERT_MASKED_OBJECT_USER (0xf1) Session Handle : 0x7004003 Response : 0:HSM Return: SUCCESS Log type : MGMT_KEY_DETAILS_LOG (1) Priv/Secret Key Handle : 262152 Public Key Handle : 0
When the CU user logs out, this CN_LOGOUT event appears only in the log
stream of the HSM that received the commands.
Example: Export a key
This example shows the audit log events that are recorded when a crypto user (CU) exports keys from a cluster with multiple HSMs.
The following event records the CU (testuser) logging into key_mgmt_util.
Time: 01/24/18 19:42:22.695884, usecs:1516822942695884 Sequence No : 0x26 Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_LOGIN (0xd) Session Handle : 0x7004004 Response : 0:HSM Return: SUCCESS Log type : MGMT_USER_DETAILS_LOG (2) User Name : testuser User Type : CN_CRYPTO_USER (1)
The CU runs an exSymKey command to export
key 7, a 256-bit AES key. The command uses key 6, a 256-bit AES
key on the HSMs, as the wrapping key.
The HSM that receives the command records a CN_WRAP_KEY event for key
7, the key that is being exported.
Time: 01/24/18 19:51:12.860123, usecs:1516823472860123 Sequence No : 0x27 Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_WRAP_KEY (0x1a) Session Handle : 0x7004003 Response : 0:HSM Return: SUCCESS Log type : MGMT_KEY_DETAILS_LOG (1) Priv/Secret Key Handle : 7 Public Key Handle : 0
Then, the HSM records a CN_NIST_AES_WRAP event for the wrapping key, key
6. The key is wrapped and then immediately unwrapped, but the HSM records
only one event.
Time: 01/24/18 19:51:12.905257, usecs:1516823472905257 Sequence No : 0x28 Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_NIST_AES_WRAP (0x1e) Session Handle : 0x7004003 Response : 0:HSM Return: SUCCESS Log type : MGMT_KEY_DETAILS_LOG (1) Priv/Secret Key Handle : 6 Public Key Handle : 0
The exSymKey command writes the exported key to a file but does not change the key on the HSM. Consequently, there are no corresponding events in the logs of other HSMs in the cluster.
Example: Import a key
This example shows the audit log events that are recorded when you import keys into the
HSMs in a cluster. In this example, the crypto user (CU) uses the imSymKey command to import an AES key into the
HSMs. The command uses key 6 as the wrapping key.
The HSM that receives the commands first records a CN_NIST_AES_WRAP event
for key 6, the wrapping key.
Time: 01/24/18 19:58:23.170518, usecs:1516823903170518 Sequence No : 0x29 Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_NIST_AES_WRAP (0x1e) Session Handle : 0x7004003 Response : 0:HSM Return: SUCCESS Log type : MGMT_KEY_DETAILS_LOG (1) Priv/Secret Key Handle : 6 Public Key Handle : 0
Then, the HSM records a CN_UNWRAP_KEY event that represents the import
operation. The imported key is assigned a key handle of 11.
Time: 01/24/18 19:58:23.200711, usecs:1516823903200711 Sequence No : 0x2a Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_UNWRAP_KEY (0x1b) Session Handle : 0x7004003 Response : 0:HSM Return: SUCCESS Log type : MGMT_KEY_DETAILS_LOG (1) Priv/Secret Key Handle : 11 Public Key Handle : 0
When a new key is generated or imported, the client tools automatically attempt to
synchronize the new key to other HSMs in the cluster. In this case, the HSM records a
CN_EXTRACT_MASKED_OBJECT_USER event when key 11 is extracted
from the HSM as a masked object.
Time: 01/24/18 19:58:23.203350, usecs:1516823903203350 Sequence No : 0x2b Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_EXTRACT_MASKED_OBJECT_USER (0xf0) Session Handle : 0x7004003 Response : 0:HSM Return: SUCCESS Log type : MGMT_KEY_DETAILS_LOG (1) Priv/Secret Key Handle : 11 Public Key Handle : 0
The log streams of other HSMs in the cluster reflect the arrival of the newly imported key.
For example, this event was recorded in the log stream of a different HSM in the same
cluster. This CN_INSERT_MASKED_OBJECT_USER event records the arrival of a
masked object that represents key 11.
Time: 01/24/18 19:58:23.286793, usecs:1516823903286793 Sequence No : 0xb Reboot counter : 0x107 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_INSERT_MASKED_OBJECT_USER (0xf1) Session Handle : 0xc008004 Response : 0:HSM Return: SUCCESS Log type : MGMT_KEY_DETAILS_LOG (1) Priv/Secret Key Handle : 11 Public Key Handle : 0
Example: Share and unshare a key
This example shows the audit log event that is recorded when a crypto user (CU) shares
or unshares ECC private key with other crypto users. The CU uses the shareKey command and provides the key handle,
the user ID, and the value 1 to share or value 0 to unshare the
key.
In the following example, the HSM that receives the command, records a CM_SHARE_OBJECT event that represents the share operation.
Time: 02/08/19 19:35:39.480168, usecs:1549654539480168 Sequence No : 0x3f Reboot counter : 0x38 Command Type(hex) : CN_MGMT_CMD (0x0) Opcode : CN_SHARE_OBJECT (0x12) Session Handle : 0x3014007 Response : 0:HSM Return: SUCCESS Log type : UNKNOWN_LOG_TYPE (5)
