Logging, debugging, and diagnostics

Logging and debugging

When using a network-atttached HSM, you can view log files using the front panel. Application log messages are handled on the client.

The current release of Security World Software uses controls for logging and debugging that differ from those used in previous releases. However, settings you made in previous releases to control logging and debugging are still generally supported in the current release, although in some situations the output is now formatted differently.

Some text editors, such as Notepad, can cause NFLOG to stop working if the NFLOG file is open at the same time as the hardserver is writing the logs.

Debug logs may include sensitive data.

CKNFAST_DEBUG

All severities from DL_Call to DL_DetailMutex may result in sensitive data being logged
JCECSP_DEBUG

No further guidance
NFJAVA_DEBUG

No further guidance
NFLOG_DETAIL

The 0x00010000 flag may result in sensitive data being logged
NFLOG_SEVERITY

All the DEBUGn settings may result in sensitive data being logged

Environment variables to control logging

The Security World for nShield generates logging information that is configured through a set of four environment variables:

NFLOG_FILE

This environment variable specifies the name of a file (or a file descriptor, if prefixed with the & character) to which logging information is written. The default is stderr (the equivalent of &2).

Ensure that you have permissions to write to the file specified by NFLOG_FILE.

NFLOG_SEVERITY

This environment variable specifies a minimum severity level for logging messages to be written (all log messages less severe than the specified level are ignored). The level can be one of (in order of greatest to least severity):

  1. FATAL

  2. SEVERE

  3. ERROR

  4. WARNING

  5. NOTIFICATION

  6. `DEBUG`N, where N can be an integer from 1 to 10 inclusive that specifies increasing levels of debugging detail, with 10 representing the greatest level of detail, although the type of output is depends on the application being debugged.

    The increasingly detailed information provided by different levels of `DEBUG`N is only likely to be useful during debugging, and we recommend not setting the severity level to `DEBUG`N unless you are directed to do so by Support.

    The default severity level is WARNING.

NFLOG_DETAIL

This environment variable takes a hexadecimal value from a bitmask of detail flags as described in the following table (the logdetail flags are also used in the hardserver configuration file to control hardserver logging; see server_settings).

Hexadecimal flag Function logdetail flags

0x00000001

This flag shows the external time (that is, the time according to your machine’s local clock) with the log entry. It is on by default.

external_time

0x00000002

This flag shows the external date (that is, the date according to your machine’s local clock) with the log entry.

external_date

0x00000004

This flag shows the external process ID with the log entry.

external_pid

0x00000008

This flag shows the external thread ID with the log entry.

external_tid

0x00000010

This flag shows the external time_t (that is, the time in machine clock ticks rather than local time) with the log entry.

external_time_t

0x00000020

This flag shows the stack backtrace with the log entry.

stack_backtrace

0x00000040

This flag shows the stack file with the log entry.

stack_file

0x00000080

This flag shows the stack line number with the log entry.

stack_line

0x00000100

This flag shows the message severity (a severity level as used by the NFLOG_SEVERITY environment variable) with the log entry. It is on by default.

msg_severity

0x00000200

This flag shows the message category (a category as used by the NFLOG_CATEGORIES environment variable) with the log entry.

msg_categories

0x00000400

This flag shows message writeables, extra information that can be written to the log entry, if any such exist. It is on by default.

msg_writeable

0x00000800

This flag shows the message file in the original library. This flag is likely to be most useful in conjunction with Security World Software-supplied example code that has been written to take advantage of this flag.

msg_file

0x00001000

This flag shows the message line number in the original library. This flag is likely to be most useful in conjunction with example code we have supplied that has been written to take advantage of this flag.

msg_line

0x00002000

This flag shows the date and time in UTC (Coordinated Universal Time) instead of local time.

options_utc

0x00004000

This flag shows the full path to the file that issued the log messages.

options_fullpath

0x00008000

This flag includes the number of microseconds in the timestamp.

options_time_us

0x00010000

This flag enables logging of potentially secret
values in generic stub log output.

msg_secrets
NFLOG_CATEGORIES

This environment variable takes a colon-separated list of categories on which to filter log messages (categories may contain the wild-card characters * and ?). If you do not supply any values, then all categories of messages are logged. This table lists the available categories:

Category Description

nflog

Logs all general messages relating to nflog.

nflog-stack

Logs messages from StackPush and StackPop functions.

memory-host

Logs messages concerning host memory.

memory-module

Logs messages concerning module memory.

gs-stub

Logs general generic stub messages. (Setting this category works like using the dbg_stub flag with the logging functionality found in previous Security World Software releases.)

gs-stubbignum

Logs bignum printing messages. (Setting this category works like using the dbg_stubbignum flag with the logging functionality found in previous Security World Software releases.)

gs-stubinit

Logs generic stub initialization routines. (Setting this category works like using the dbg_stubinit flag with the logging functionality found in previous Security World Software releases.)

gs-dumpenv

Logs environment variable dumps. (Setting this category works like using the dbg_dumpenv flag with the logging functionality found in previous Security World Software releases.)

nfkm-getinfo

Logs nfkm-getinfo messages.

nfkm-newworld

Logs messages about world generation.

nfkm-admin

Logs operations using the Administrator Card Set.

nfkm-kmdata

Logs file operations in the kmdata (Linux) or %NFAST_KMDATA% (Windows) directory.

nfkm-general

Logs general NFKM library messages.

nfkm-keys

Logs key loading operations.

nfkm-preload

Logs preload operations.

nfkm-ppmk

Logs softcard operations.

serv-general

Logs general messages about the local hardserver.

serv-client

Logs messages relating to clients or remote hardservers.

serv-internal

Logs severe or fatal internal errors.

serv-startup

Logs fatal startup errors.

servdbg-stub

Logs all generic stub debugging messages.

servdbg-env

Logs generic stub environment variable messages.

servdbg-underlay

Logs messages from the OS-specific device driver interface

servdbg-statemach

Logs information about the server’s internal state machine.

servdbg-perf

Logs messages about the server’s internal queuing.

servdbg-client

Logs external messages generated by the client.

servdbg-messages

Logs server command dumps.

servdbg-sys

Logs OS-specific messages.

pkcs11-sam

Logs all security assurance messages from the PKCS #11 library.

pkcs11

Logs all other messages from the PKCS #11 library.

rqcard-core

Logs all card-loading library operations that involve standard message passing (including slot polling).

rqcard-ui

Logs all card-loading library messages from the current user interface.

rqcard-logic

Logs all card-loading library messages from specific logics.

You can set a minimum level of hardserver logging by supplying one of the values for the NFLOG_SEVERITY environment variable in the hardserver configuration file, and you can likewise specify one or more values for the NFLOG_CATEGORIES environment variable. For detailed information about the hardserver configuration file settings that control logging, see server_settings.

If none of the four environment variables are set, the default behavior is to log nothing, unless this is overridden by any individual library. If any of the four variables are set, all unset variables are given default values.

Logging from the nShield CSP and CNG (Windows)

By default, logging is disabled for the nShield CSP and CNG.

To enable logging, use a suitable registry editor such as regedit.

Depending on whether the program you wish to debug is 64-bit or 32-bit based, you will have to create respective registry keys if they do not already exist.

For a 64-bit program on a 64-bit OS, create the following registry key if it does not already exist:

HKEY_LOCAL_MACHINE\SOFTWARE\nCipher\Cryptography

For a 32-bit program on a 64-bit OS, create the following registry key if it does not already exist:

HKEY_LOCAL_MACHINE\SOFTWARE\WOW6432Node\nCipher\Cryptography

Open the registry at the required Cryptography key as described above, and under the key create the following variables.

  1. Create a new string variable named PathName.

  2. Open the PathName variable and provide a value which is a suitable path to where you want the log file(s) to be placed (for example, C:\Users\MyName\Documents.) Do not give a log file name. The log file name(s) will be created automatically when logging starts.

    It must be possible for the provider to write to the specified path.

  3. Create a new DWORD (32 bit) variable named LogLevel.

  4. Open the LogLevel variable and provide a suitable value (for example, 2).

    Permitted values for LogLevel are:

    Value Output

    0

    Messages are sent to the event log.

    1

    Error messages are sent to the log file.

    2

    Function calls and error messages are sent to the log file.

    3

    All information, including debugging information, is sent to the log file.
    Do not set this value to 3 unless either you are asked to do so by Support or you are debugging your own code. At this level of logging, a single SSL connection generates approximately 30 kilobytes of log messages. In addition, sensitive information may appear in the log file.
    If LogLevel is not set, then the provider only logs messages of warning severity or greater (equivalent to setting NFLOG_SEVERITY=warning).

If neither PathName nor LogLevel are set for the CSP or CNG, logging remains disabled.

If logging is successfully enabled, the log file(s) should appear at the location specified in PathName, and will have names similar to:

  • nfdebug.txt

  • ncspdddebug.txt

  • nckspswdebug.txt

Logging and debugging information for PKCS #11

In order to get PKCS #11 logging and debugging output, you must set the CKNFAST_DEBUG variable. A debug output file (with path) can also be set using the CKNFAST_DEBUGFILE variable. These variables can be set in the environment or the /opt/nfast/cknfastrc (Linux) or %NFAST_HOME%\cknfastrc (Windows) file. Normally settings in the environment should override the same settings (if any) in the cknfastrc file. You can specify any appropriate PKCS #11 categories using the NFLOG_CATEGORIES environment variable.

To produce PKCS #11 debug output, the CKNFAST_DEBUG variable can be a given value from 1 through to 11, where the greater the value the more detailed debug information is provided. A value of 7 is a reasonable compromise between too little and too much debug information. A value of 0 switches the debug output off.

This environment variable takes a colon-separated list of categories on which to filter log messages (categories may contain the wildcards characters * and ?).

The following table maps PKCS #11 debug level numbers to the corresponding NFLOG_SEVERITY value:

PKCS #11 debug level PKCS #11 debug meaning NFLOG_SEVERITY value Output in log

0

DL_None

NONE

1

DL_EFatal

FATAL

"Fatal error:"

2

DL_EError

ERROR

"Error:"

3

DL_Fixup

WARNING

"Fixup:"

4

DL_Warning

WARNING

"Warning:"

5

DL_EApplic

ERROR

"Application error:"

6

DL_Assumption

NOTIFICATION

"Unsafe assumption:"

7

DL_Call

DEBUG2

">> "

8

DL_Result

DEBUG3

"< "

9

DL_Arg

DEBUG4

"> "

10

DL_Detail

DEBUG5

"D "

11

DL_DetailMutex

DEBUG6

"DM "

Hardserver debugging (PCIe and USB HSMs)

Hardserver debugging is controlled by specifying one or more servdbg-* categories (from the NFLOG_CATEGORIES environment variable) in the hardserver configuration file; server_settings in the Hardserver configuration file chapter. However, unless you also set the NFAST_DEBUG environment variable to a value in the range 1 – 7, no debugging is produced (regardless of whether or not you specify servdbg-* categories in the hardserver configuration file). This behavior helps guard against the additional load debugging places on the CPU usage. You can set the desired servdbg-* categories in the hardserver configuration file, and then enable or disable debugging by setting the NFAST_DEBUG environment variable.

The NFAST_DEBUG environment variable controls debugging for the general stub or hardserver. The value is an octal number, in the range 1 – 7. It refers bitwise to a number of flags:

Flag Result

1

Generic stub debugging value.

2

Show bignum values.

4

Show initial NewClient or ExistingClient command and response.

For example, if the NFAST_DEBUG environment variable is set to 6, flags 2 and 4 are used.

If the NFAST_DEBUG environment variable value includes flag 1 (Generic stub debugging value), the logdetail value in the hardserver configuration file (one of the values for the NFLOG_DETAIL environment variable) controls the level of detail printed.

Do not set the NFAST_DEBUG environment variable to a value outside the range 1 – 7. If you set it to any other value, the hardserver does not start.

Debugging information for Java

This section describes how you can specify the debugging information generated by Java.

Setting the Java debugging information level

In order to make the Java generic stub output debugging information, set the Java property NFJAVA_DEBUG. The debugging information for NFJAVA, NFAST, and other libraries (for example, KMJAVA) can all use the same log file and have their entries interleaved.

You set the debugging level as a decimal number. To determine this number:

  1. Select the debugging information that you want from the following list:

    NONE = 0x00000000 (debugging off)
MESS_NOTIFICATIONS = 0x00000001 (occasional messages including important errors)
MESS_VERBOSE = 0x00000002 (all messages)
MESS_RESOURCES = 0x00000004 (resource allocations)
FUNC_TRACE = 0x00000008 (function calls)
FUNC_VERBOSE = 0x00000010 (function calls + arguments)
REPORT_CONTEXT = 0x00000020 (calling context e.g ThreadID and time)
FUNC_TIMINGS = 0x00000040 (function timings)
NFJAVA_DEBUGGING = 0x00000080 (Output NFJAVA debugging info)

  2. Add together the hexadecimal value associated with each type of debugging information.

    For example, to set NFJAVA_DEBUGGING and MESS_NOTIFICATIONS, add 0x00000080 and 0x00000001 to make 0x00000081.

  3. Convert the total to a decimal and specify this as the value for the variable.

    For example, to set NFJAVA_DEBUGGING and MESS_NOTIFICATIONS, include the line:

    NFJAVA_DEBUG=129

    For NFJAVA to produce output, NFJAVA_DEBUG must be set to at least NFJAVA_DEBUGGING + MESS_NOTIFICATIONS. Other typical values are:

    • 255: All output

    • 130: nfjava debugging and all messages (NFJAVA_DEBUGGING and MESS_VERBOSE)

    • 20: function calls and arguments and resource allocations (FUNC_VERBOSE and MESS_RESOURCES)

Setting Java debugging with the command line

You can set the Java debug options by immediately preceding them with a -D. Use the NJAVA_DEBUGFILE property to direct output to a given file name, for example:

java -DNFJAVA_DEBUGFILE=myfile -DNFJAVA_DEBUG=129 -classpath .... classname
Do not set NFJAVA_DEBUG or NFJAVA_DEBUGFILE in the environment because Java does not pick up variables from the environment.

If NFJAVA_DEBUGFILE is not set, the standard error stream System.err is used.

Set these variables only when developing code or at the request of Support.
Debug output contains all commands and replies sent to the hardserver in their entirety, including all plain texts and the corresponding cipher texts as applicable.

appliance-cli: system logs utility

See appliance-cli

Diagnostics and system information

Besides the diagnostic tools described in this section, we also supply a performance tool that you can use to test Web server performance both with and without an nShield HSM. This tool is supplied separately. If you require a copy, contact your Sales representative.

NIC Reporting (network-attached HSMs)

Networking information regarding NIC (Network Interface Card) status and address details can be reported via the stattree output.

NIC status and address details are disabled by default. To enable or disable NIC details in the stattree output is done via the configuration menu, System > System Configuration > NIC exposure config > Device Status and select the appropriate setting (Yes or No). Similarly for enabling or disabling the NIC addressing which is done via the Address Reporting option.

Reporting NIC addressing is only performed when device status is enabled.

A typical stattree report with NIC status and address details enabled looks like:

+#HostSysInfo:
   +SystemFans:
      +#1:
         -CurrentFanRPM        6240
      +#2:
         -CurrentFanRPM        6240
      +#3:
         -CurrentFanRPM        6240
      +#4:
         -CurrentFanRPM        6300
   +NetworkInterfaces:
      +#1:
         -InterfaceName        eth0
         -InterfaceLinkState   up
         +NetworkAddresses:
            +#1:
               -InterfaceNetworkAddress 172.23.135.127
      +#2:
         -InterfaceName        eth1
         -InterfaceLinkState   down
         +NetworkAddresses:

nShield HSM tamper log (network-attached HSMs)

The nShield HSM tamper log contains:

  • The date and time of any tamper events

  • Whether the tamper detection functionality was ever disabled or re-enabled.

    It is no longer possible to disable tamper detection.

You view the tamper log using the nShield HSM front panel, by selecting System > System information > View tamper log. You cannot erase the tamper log.

How data is affected when a module loses power and restarts

nShield modules use standard RAM to store many kinds of data, and data stored in such RAM is lost in the event that a module loses power (either intentionally, because you turned off power to it, or accidentally because of a power failure).

Therefore, after restoring power to a module, you must reload any keys that had been loaded onto it before it lost power. After reloading, the KeyIDs are different.

Likewise, after restoring power to a module, you must reload any cards that were loaded onto it before it lost power.

However, data stored in NVRAM is unaffected when a module loses power.

If you are using multiple nShield modules in the same Security World, and have the same key (or keys) loaded onto each module as part of a load-sharing configuration, loss of power to one module does not affect key availability (as long as at least one other module onto which the keys are loaded remains operational). However, in such a multiple-module system, after restoring power to a module, you must still reload any keys to that module before they can be available from that module.