Network Trust Link Service

The network trust link service (NTLS) is the cryptographic services dispatcher of the SafeNet Luna Network HSM appliance. On system startup, NTLS runs as a daemon and listens for incoming connection requests on TCP/IP sockets. Using Secure Sockets Layer, NTLS secures communication between the appliance and a client, each party authenticating the other with certificates and encrypting data exchanged.

Thales has arranged NTLS into two principal components and the organization of NTLS log messages in this document reflects this architecture. A generic datapath engine manages the socket communications. This engine is common across Luna appliances (e.g., Luna SA, Luna SP and Luna IS use the same engine). A product-specific command processor parses and responds to the messages NTLS receives from and sends back to the client. This document makes explicit note for older messages; otherwise, assume that the descriptions apply for more current product releases.

Facility Keyword

Software Process

Log File

Local5

NTLS [pid]

lunalogs

>Datapath: Expected Log Messages

>Datapath: Unexpected Log Messages

>Luna SA Command Processor: Expected Log Messages

>Luna SA Command Processor: Unexpected Log Messages

Datapath: Expected Log Messages

The following log messages are normal and expected entries in the log files from the datapath engine of NTLS.

Startup

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : Starting up NTLS........
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : luna_engine_preload: SUCCESSFULLY  loaded
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : 1 = ENGINE_ctrl_cmd_string(...SO_PATH...
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : 1 = ENGINE_ctrl_cmd_string(...ID...) 
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : 1 = ENGINE_ctrl_cmd_string(...LOAD...
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : luna_engine_load: SUCCESSFULLY  enabled for ALL ops
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : HSM crypto support for data path* SSL operations enabled**
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : "Luna SA 5.0 Command Processor" module version 1.0 loaded
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : NTLS data path configured with 5 inbound worker threads and 5 outbound worker threads
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : NTLS is online and operational.
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : Data path TCP keep alive is configured as : TCP_KEEPIDLE = 10 sec : TCP_KEEPINTVL = 10 sec : TCP_KEEPCNT = 2 retries
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : Data path TCP keep alive is configured as : TCP_KEEPIDLE = 10 sec : SSL cipher list set to AES256-GCM-SHA384

The first message indicates that NTLS is starting up. The next five messages trace the progress of the SSL start up sequence. The remaining messages show the progress through to a successful startup.

* "NTLS” in older implementations

** Or “disabled” or “NOT enabled” if the keys-in-hardware option is enabled but the SSL engine failed to load (“luna_engine_load: failed to ENGINE_set_default for ALL ops”).

Failed to Enable SSL Engine for All Operations

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : luna_engine_load: failed to ENGINE_set_default for ALL ops

This message indicates that the SSL engine was unable to initialize properly.

Client Connections

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : Incoming connection request... : 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : Connection accepted from: 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : Handshake result from: 192.168.0.100/40847, result: Success
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : NTLS Client "192.168.0.100" connected and authenticated : 192.168.0.100/40847.
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : Connection terminating:  192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : NTLA client "192.168.0.100" has disconnected: 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : Receive timer expired for client "192.168.0.100". Terminate client connection: 192.168.0.100/40847*
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : Receive timer expired for client "192.168.0.100" : 192.168.0.100/40847**

These messages indicate connect establishment and termination by NTLS. You should find pairs of connection accepted and disconnected messages in the logs. The last two messages result when a client connects but is inactive for a period configured for NTLS.

* This message results if the timeout is for a scheduled cleanup.

** This message results if the timeout is not for a scheduled cleanup.

Client Credentials Cannot be Verified

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : Client credentials cannot be verified. Connection terminated : 192.168.0.100/40847

This message indicates that the client connection request could not be completed. A possible root cause is that the client’s certificate is invalid (e.g., has a wrong IP address or hostname).

Cache Monitor

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0 : Client certificate verify location monitor started
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0 : Detected client certificate removed from verify location.  Flush verify location cache
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0 : Client certificate verify location monitor terminated

These messages indicate that NTLS has started to monitor client certificates registered with the process.

Connection Instance Added and Removed

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0 : NTLA Client "192.168.0.100" Connection instance removed : 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0 : NTLA Client "192.168.0.100" connected and authenticated : 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0 : NTLA Client "192.168.0.100" has disconnected: 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0 : NTLA Client "192.168.0.100" has disconnected: 192.168.0.100/40847

These messages indicate NTLS’s action to add and remove connection instances.

Client Credentials Cannot be Verified

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0 : Client credentials cannot be verified. Connection terminated : 192.168.0.100/40847

This message indicates that an application connected to NTLS but did not provide the SSL credentials to complete authentication.

Handshake Failed

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000711 : Fail to establish a secure channel with client : 192.168.0.100/40847 : RC_SSL_FAILED_HANDSHAKE

This message indicates that an application attempted to connect with SSL credentials that did not conform to the algorithms and/or cryptographic strength expected by NTLS.

Unable to Initialize Server Socket

2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical : 0xc0000500 : NTLS listening port could not Bind : RC_SOCKET_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000500 : Unable to initialize data path* server socket : RC_SOCKET_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000500 : NTLS initialization failed : RC_SOCKET_ERROR

These messages indicate that NTLS was unable to initialize the server socket. A possible root cause is that the network interface is not properly configured.

* “NTLS” in older implementations.

Connected to Server

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : 192.168.0.100 connected to server : 192.168.0.100/40847

This message indicates that NTLS has successfully established an outgoing connection with a peer or remote server.

Shutting Down

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : Shutting down NTLS....
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0 : Intiating [sic] dispatch termination.
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0 : Dispatching has been terminated.
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0 : Terminating.
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : "Luna SA 5.0 Command Processor" shut downed
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : NTLS terminated

These messages show the progression of steps as NTLS terminates.

Datapath: Unexpected Log Messages

Under normal circumstances, you should not see any of these log messages. If you do so, please consult the user documentation for guidance on how to correct the problem.

NTLS Terminating

2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000102 : Terminating.
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000102 : Failed to start as daemon. Terminating.
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000102 : Failed to initialize application. Terminating.
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000102 : Failed to create server. Terminating.

These messages indicate that NTLS failed at startup. Possible root causes for the first message are a failure to create internal data structures needed by NTLS or a failure to generate the private key and certificate needed by NTLS.

Failed to Load SSL Engine

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : luna_engine_load: failed to ENGINE_by_id

This message indicates that OpenSSL was unable to load the specified engine. A possible root cause is the wrong engine identifier specified in the OpenSSL configuration file.

Skip C_Initialize

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : 1 = ENGINE_ctrl_cmd_string(...SKIP_C_INITIALIZE...)

This message indicates that the OpenSSL engine for LunaCA3 skipped the call the C_Initialize. Luna appliances do not use the LunaCA3 engine.

Configured for RSA Operations

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : luna_engine_load: SUCCESSFULLY  enabled for RSA ops

This message indicates that the SSL engine used by NTLS is configured only for RSA operations.

Failed to Pre-Load SSL Engine

Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : luna_engine_preload: failed to load

This message indicates that the SSL engine was unable to preload. A possible root cause is the wrong engine identifier configured on the Luna appliance.

Failed to Enable SSL Engine for RSA Operations

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : luna_engine_load: failed to ENGINE_set_default for RSA ops

This message indicates that the SSL engine was unable to initialize properly for RSA operations.

Failed to Initialize

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0 : Missing command processor library for NTLS.
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000102 : Command processor module not found : "Luna SA 5.0 Command Processor" : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical : 0xc0000105 : cp_get_supported_versions function not found in command processor "Luna SA 5.0 Command Processor" : RC_FUNCTION_NOT_SUPPORTED
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical : 0xc0000105 : cp_initialize_p function not found in command processor "Luna SA 5.0 Command Processor" : RC_FUNCTION_NOT_SUPPORTED
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical : 0xc0000105 : cp_get_processor_name_p function not found in command processor "Luna SA 5.0 Command Processor" : RC_FUNCTION_NOT_SUPPORTED
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical : 0xc0000105 : cp_shutdown function not found in command processor "Luna SA 5.0 Command Processor" : RC_FUNCTION_NOT_SUPPORTED
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000105 : cp_client_registration_observer function not found in command processor "Luna SA 5.0 Command Processor" : RC_FUNCTION_NOT_SUPPORTED
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000105 : cp_configure function not found in command processor "Luna SA 5.0 Command Processor" : RC_FUNCTION_NOT_SUPPORTED
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 : Failed to initialize "Luna SA 5.0 Command Processor" module version 1.0 for data path module version 1.0 : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5  err  NTLS [1234]: error :  0xc0000102 : Failed to initialize "Luna SA 5.0 Command Processor" module version 1.0 : RC_GENERAL_ERROR*
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000105 : "Luna SA 5.0 Command Processor" module version 1.0 is incompatable [sic] with data path : RC_FUNCTION_NOT_SUPPORTED
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000500 : Unable to initialize openssl library : RC_SOCKET_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000500 : Unable to initialize openssl server context : RC_SOCKET_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000102 : Application specific initialization failed for NTLS.
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000102 : Unable to initialize dispatcher.
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000402 : Chrystoki configuration client certificate file name invalid: RC_FILE_NAME_INVALID
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000402 : Chrystoki configuration client private key file name invalid: RC_FILE_NAME_INVALID
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000402 : Chrystoki configuration ssl configuration file name invalid: RC_FILE_NAME_INVALID
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000102 : Failed to create private key/certificate: RC_GENERAL_ERROR, error: -1

These messages indicate a failure of the datapath component to initialize itself at NTLS startup.

* For older implementations.

No Command Processor Module Configured

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : Data path is not configured with a command processor module.  Use default command processor setting

This message indicates an error in how NTLS is configured.

Fail to Accept Connections

2012 Feb 29 12:05:01 myLuna  local5  err  NTLS [1234]: error :  0xc0000002 : Unable to create a new connection.
2012 Feb 29 12:05:01 myLuna  local5  err  NTLS [1234]: error :  0xc0000002 : Accept failed. Reason: RC_GENERAL_ERROR

These messages indicate an NTLS failure to establish the TCP/IP socket necessary to listen for and accept connections from clients.

Fail to Create Client Connection

2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000500 : Fail to create connection instance : 192.168.0.100/40847 : RC_SOCKET_ERROR
2012 Feb 29 12:05:01 myLuna  local5 warn  NTLS [1234]: warning : 0xc0000500 : Fail to accept a client TCP connection : RC_SOCKET_ERROR

These messages indicate a failure to create a client connection on an incoming request.

Cache Monitor Failed

2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error :  0xc0000002 : CA cache monitor fail to initialize : RC_GENERAL_ERROR

This message indicates that the thread spawned to monitor client certificates failed to initialize.

Connection Instance Failures

2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error :  0xc0000002 : Fail to create timer object for connection instance : 192.168.0.100/40847 : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error :  0xc0000004 : Fail to create ssl object for connection instance : 192.168.0.100/40847 : RC_UNEXPECTED
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000102 : Client request header malformed : 192.168.0.100/40847 : RC_DATA_INVALID
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000001 : Fail to allocate command buffer : 192.168.0.100/40847 : RC_MEMORY_ALLOCATION
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error :  0xc0000002 : Fail to forward client request to command processor module : 192.168.0.100/40847 : RC_GENERAL_ERROR

These messages indicate a failure of NTLS to add or remove a client connection instance.

Non-Luna Client Connect Attempt

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000004 : Connection attempt from non-Luna client : 192.168.0.100/40847 : RC_UNEXPECTED

This message indicates that an application attempted to connect to the Luna appliance via NTLS but did not provide the proper SSL message exchange expected.

Command Process Unloaded

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : Command Processor module unloaded

This message indicates that NTLS unloaded its command processor module (a shared object library).

SSL Certificates Problems

2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000701 : Bad SSL handle while determining hostname: RC_SSL_CTX_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc000070a : Failed to get current certificate while determining hostname: RC_SSL_INVALID_CERT_STRUCTURE
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc000070a : Failed to get certificate text while determining hostname: RC_SSL_INVALID_CERT_STRUCTURE
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc000070a : Invalid client certificate while determining hostname: RC_SSL_INVALID_CERT_STRUCTURE
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000701 : Unable to retrieve native SSL CTX handle: RC_SSL_CTX_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000702 : SSL error setting cipher list: RC_SSL_CIPHER_LIST_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000402 : Chrystoki configuration client certificate path invalid: RC_FILE_NAME_INVALID
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000703 : Load verify locations failed for: CACert.pem, RC_SSL_CERT_VERIFICATION_LOCATION_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000703 : Load verify locations failed for single client: CACert.pem, RC_SSL_CERT_VERIFICATION_LOCATION_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000402 : Chrystoki configuration server certificate filename invalid: RC_FILE_NAME_INVALID
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000704 : Chrystoki using server certificate failed: /usr/lunasa/vts/server/server.pem, RC_SSL_LOAD_SERVER_CERT_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000402 : Chrystoki configuration server private key filename invalid: RC_FILE_NAME_INVALID
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000705 : Error loading the server private key: RC_SSL_LOAD_SERVER_PRIVATE_KEY_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000706 : Error checking the server private key: RC_SSL_VALIDATE_SERVER_PRIVATE_KEY_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000406 : Fail to retrieve host IP Address : RC_SOCKET_ADDRESS_INVALID
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000406 : Fail to retrieve host port : RC_SOCKET_ADDRESS_INVALID
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000406 : Unable to create context. : RC_SOCKET_ADDRESS_INVALID
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000002 : Failed to initialize server for address 192.168.0.100/40847 : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000002 : Chrystoki configuration client certificate filename invalid: RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000708 : Chrystoki using client certificate failed: CACert.pem, RC_SSL_LOAD_CLIENT_CERT_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000402 : Chrystoki configuration client private key filename invalid: RC_FILE_NAME_INVALID
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc000070b : Error loading the client private key: RC_SSL_LOAD_CLIENT_PRIVATE_KEY_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000402 : Chrystoki configuration server certificate authority filename invalid: RC_FILE_NAME_INVALID
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000703 : Error loading server certificate authorities: RC_SSL_CERT_VERIFICATION_LOCATION_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000002 : Unable to update context. : RC_GENERAL_ERROR

These messages indicate a failure of the underlying communication mechanism NTLS uses to exchange messages between a client application and the Luna appliance.

Client Authentication Failures

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : Failed writing identity string. Reason: RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : Failed connect. Reason: RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : Failed handshake. Reason: RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : Identify result from: 192.168.0.100/40847, result: RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : Failed reading identity string. Reason: RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5  err  NTLS [1234]: error :  0xc0000002 : Fail to forward dataless client request to command processor module : 192.168.0.100/40847 : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000102 : Client request header malformed : 192.168.0.100/40847 : RC_DATA_INVALID
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000001 : Fail to allocate command buffer : 192.168.0.100/40847 : RC_MEMORY_ALLOCATION
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : Failed reading command buffer. Reason: RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5  err  NTLS [1234]: error :  0xc0000002 : Fail to forward client request to command processor module : 192.168.0.100/40847 : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : Failed writing to client Reason: RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : Last write before reinitializing failed. Reason: RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : Expected cancelled operation, actual: RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : Reinitializing connection for: 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5  err  NTLS [1234]: error :  0xc0000002 : Fail to get response buffer: 192.168.0.100/40847 : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5  err  NTLS [1234]: error :  0xc0000002 : Expecting client certificate. None received.
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : Unable to retrieve client certificate.: 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0xc0000002 : cp_server_connected failed : 192.168.0.100/40847

These messages indicate a failure of NTLS to verify the client requesting to connect to the Luna appliance.

Port Monitoring Failures

2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000406 : Fail to retrieve host IP Address : RC_SOCKET_ADDRESS_INVALID
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000406 : Fail to retrieve host port : RC_SOCKET_ADDRESS_INVALID
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000500 : Fail to set socket linger option : RC_SOCKET_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000500 : Fail to set socket reuse option : RC_SOCKET_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000500 : Data path listening port could not Bind : RC_SOCKET_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000500 : Fail to set socket non-blocking option : RC_SOCKET_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical :  0xc0000002 : Data path listening port not listening

These messages indicate a failure of NTLS to set up the port upon which the process will listen for incoming connection requests.

Could Not Initialize Command Processor

2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error :  0xc0000002 : Failed to initialize "Luna SA 5.0 Command Processor"  module version 1.0 : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error :  0xc0000002 : Failed to initialize command processor cleanup mechanism.
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 : Failed to create Appliance Handler for NTLS: RC_GENERAL_ERROR.
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 : Failed to initialize Appliance Handler for NTLS: RC_GENERAL_ERROR.
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 : Failed to create server for NTLS: RC_GENERAL_ERROR.
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 : Failed to create thread pool for NTLS: RC_GENERAL_ERROR.

These messages indicate a failure to initialize the command processor, a shared library module within the Luna appliance.

Datapath Debug Messages

2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Data path is using OpenSSL 0.9.5a 1 Apr 2000
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0xc0000002     Unexpected connect response in <state string>
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0xc0000002     Unexpected client response in <state string>
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0xc0000002     Unexpected handshake response in <state string>
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0xc0000002     Unexpected read response in <state string>
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0xc0000002     Unexpected write response in <state string>

Thales does not enable logging of debug messages for NTLS. If in future Thales does enable this level of log messages, the messages above show examples of what you might find in the log files. In the examples above, <state string> is one of the following set: [IDENTITY STATE | HANDSHAKE STATE | PROCESSING STATE | HEADER STATE | COMMAND STATE | CONNECTING STATE | IDENTIFYING STATE | OUT OF SERVICE STATE | REINITIALIZING STATE].

NTLS Crash and Burn

2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: info : 0 : NTLS CRASH AND BURN! Stack dump saved to /var/log/ntls_bt_2012-02-29_12:05:01
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: info : 0 : NTLS CRASH AND BURN and unable to dump the stack!

These messages indicate a programming error. The first message indicates that NTLS terminated abnormally (on one of SIGSEGV, SIGILL or SIGBUS signals), generating a stack trace file in the process. An example stack trace file is: ntls_bt_2012-02-29_12:05:01 found in the logs directory. Forwarding this file to Thales product engineering may assist a developer to isolate the reason for the abnormal termination.  The second message indicates an abnormal termination but with no resulting stack trace created.

Luna SA Command Processor: Expected Log Messages

The following log messages are normal and expected entries in the log files from the Luna SA command processor of NTLS.

Configured with Worker Threads

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : SA command processor configured with 50 worker threads

This message indicates that NTLS has successfully started its command processor.

HTL Configured

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0 : Listening for HTL kill requests

This message indicates that host trust link (HTL) is configured and started.

USB Backup and PKI Bundle Device

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: USB token: Backup1 with serial number: 123456 has been undeployed!
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: Re-deployed the  USB token: Backup1 with serial number: 123456 to Virtual token list
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: Added USB token: Backup1 with serial number: 123456 at slot: 4 and container id: 8 to Virtual token list
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: Deployed token Backup1 with Serial Number 123456 inserted into slot 4!
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: NON Deployed token Backup1 with Serial Number 123456 inserted into slot 4!
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: NON Deployed token with no label and Serial Number 123456 inserted into slot 4!
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: Deployed token Backup1 with Serial Number 123456 ejected from slot 4!
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: NON Deployed token Backup1 with Serial Number 123456 ejected from slot 4!
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: NON Deployed token with no label and Serial Number 123456 ejected from slot 4!
2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : Waited to find PKI token: PKIToken with serial number: 123456 at slot: 4

These messages indicate actions associated with devices connected to the USB port on the Luna appliance. Luna SA supports secure backup from the internal HSM to a USB-attached backup device. Luna SA also supports a “PKI bundle” feature for root keys stored and accessed on a USB-attached device (e.g., Luna G5). The examples above show “Backup1” for the label name of the USB-attached device but this label could be PKI bundle-centric (e.g., “RootCA1”) – the messages are common for both use cases.

Command Processor Instance Removed

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: Command processor instance for client 192.168.0.100 removed : 192.168.0.100/40847

This message indicates that a client connection terminated and NTLS removed the command processor instance allocated for this client.

HTL Kill Request

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info :  0 : Received NTLS kill request from HTL for client 192.168.0.100

This message indicates that the host trust link was forcibly terminated for the specified client.

Shutdown

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : "Luna SA 5.0 Command Processor" shut downed

This message indicates an orderly shutdown of the Luna SA command processor.

Luna SA Command Processor: Unexpected Log Messages

Under normal circumstances, you should not see any of these log messages.  If you do so, please consult the user documentation to seek guidance on how to correct the problem.

Keep-alive Timer Failures

2012 Feb 29 12:05:01 myLuna  local5 warn  NTLS [1234]: warning : 0xc0000002 : Fail to create client command keepalive timer : 192.168.0.100/40847 : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 warn  NTLS [1234]: warning : 0 : Client command keepalive function is disabled : 192.168.0.100/40847

These messages indicate a failure to start the keep-alive timer that monitors for inactive client connections.

Startup and Operational Failures

2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 : Fail to allocate connection request response buffer [size = 100] : 192.168.0.100/40847 :RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 : Fail to allocate connection request response buffer [size = 100] : 192.168.0.100/40847 :RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 : Fail to allocate termination response buffer [size = 100] : 192.168.0.100/40847 :RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 : Fail to allocate slot state response buffer [size = 100] : 192.168.0.100/40847 :RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 : Fail to allocate response message buffer [type = 7] [size = 100] : 192.168.0.100/40847 :RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 : Fail to allocate response message buffer [type = 7] [size = 100] : 192.168.0.100/40847 :RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 : Fail to allocate a keep alive message buffer [size = 100] : 192.168.0.100/40847 :RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 Fail to initialize token interface : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 Fail to initialize App ID mapping object : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 Failed to initialize remote PED support.
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 Fail to initialize client registration database : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 Fail to populate client registration database : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 Fail to reset client registration entries flags : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 Fail to create token manager object : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 Fail to Initialize VToken Manager : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000105 Version 5.0 is not supported by command processor version 1.0 : RC_FUNCTION_NOT_SUPPORTED
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 : Connection count is not incremented for APP ID [b43 : 0 : 1] : [5 : 1] 192.168.0.100/40847 :RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 : Out of Memory Error in ConnectionClass::AttachResponseBuffer SetResponseBuffer : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000001 Fail to create command processor instance for client 192.168.0.100 : 192.168.0.100/40847 : RC_MEMORY_ALLOCATION
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 Invalid client registration observer.
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 Invalid client registration observer operation: 9.
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 Fail to return a command response to 192.168.0.100 : 192.168.0.100/40847 : RC_GENERAL_ERROR

These messages indicate a failure of NTLS to start the component responsible for managing connection queues and for processing HSM-specific requests for service from clients.

Fail to Initialize Appliance Statistics

2012 Feb 29 12:05:01 myLuna  local5 warn  NTLS [1234]: warning : 0xc0000002 : Fail to initialize appliance statistic object : RC_GENERAL_ERROR

This message indicates a failure of the Luna SA command processor to initialize data structures necessary to compile operational statistics.  NTLS continues to operate.

HTL Required

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : Client 192.168.0.100 requires HTL; HTL status is 5

This message indicates that the client is configured to use HTL but the host trust link is not up.

HTL Failure

2012 Feb 29 12:05:01 myLuna  local5  err  NTLS [1234]: error :  0 : Exception in HTL kill listener: <exception string>

This message indicates a failure of the HTL component of the Luna SA 5 command processor.

Client Credentials Cannot be Verified

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : Client credentials cannot be verified : 192.168.0.100/40847

This message indicates that the client credentials cannot be verified.  A possible root cause is an inconsistent entry in the client certificate for IP address or host name.

Client Terminating

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: info : 0 : Client 192.168.0.100 requested termination : 192.168.0.100/40847

This message indicates that the client is terminating under normal (i.e., graceful) circumstances.

Unsupported Command

2012 Feb 29 12:05:01 myLuna  local5 info  NTLS [1234]: Client attempted unsupported command 0x00000000.

This message indicates that the command request received by NTLS is unexpected. A possible root cause is from an application that calls a PKCS#11 function that NTLS is not programmed to either accept or ignore.

Failure to Retrieve Container List

2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0x300000 : Fail to retrieve container list : LUNA_RET_DEVICE_ERROR
2012 Feb 29 12:05:01 myLuna  local5 crit  NTLS [1234]: critical : 0x300000 : Unable to load system containers! : LUNA_RET_DEVICE_ERROR

These messages indicate that NTLS was unable to retrieve from the internal HSM its representation of how cryptographic objects are segregated from one another. A possible root cause is a loss of communication between the internal HSM and its associated device driver.

Luna SA Command Processor Debug Messages

2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Transient APP ID Mapping [5 / 5 : 1] removed :192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Open session : [1 / 0 : 1 : 20]  : [5 : 1] : 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Open session APP ID major [b43] doesn't have 0x80000000 set : [5 : 1] : 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Create transient APP ID mapping for open session : [b43 : 0 : 1] : [5 : 1] : 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : APP ID mapping already exist : [b43 : 0 : 1] : [5 : 1] : 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Open session get APP ID : [b43 : 0 : 1] : [5 : 1] : 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Close all sessions : [b43 : 0 : 1] : [5 : 1] : 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Open Access : b43 : 0 : 1] :192.168.0.100/40847 1] : 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Create persistent APP ID mapping for [b43 : 0 : 1] : [5 : 1] : 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Change existing APP ID mapping for [5 : 1] to persistent state : [80000005 : 1] : 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Closing Access for [b43 : 0 : 1] : 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Close Access APP ID major [b43] doesn't have 0x80000000 set : [5 : 1] : 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : APP ID Mapping [b43 : 0 : 1] : [5 : 1] removed :192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Bypassed LUNA_SEED_RANDOM command : 192.168.0.100/40847
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Closed Session : [5 : 1 : 266]
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Closed All Sessions : [5 / 5 : 1]
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Removed All Sessions : [5 / 5 : 1 : 20]
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Opened Session : [5 / 5 : 1 : 20 : 266]
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Created VToken for 4/8.
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : viper slot = 1
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Found 20 partitions on HSM.
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Looking for index for token with S/N 123456 amount 4 tokens.
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Token 4 has S/N 123456.
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Token 4 is dirty.
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Entering USBSlotHandler::MonitorSlot for slot 4
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Leaving USBSlotHandler::MonitorSlot for slot 4
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Entering USBSlotHandler::MonitorConfig for slot 4
2012 Feb 29 12:05:01 myLuna  local5 debug  NTLS [1234]: debug : 0 : Leaving USBSlotHandler::MonitorConfig for slot 4

Thales does not enable logging of debug messages for NTLS. If in future Thales does enable this level of log messages, the messages above show examples of what you might find in the log files. These messages are for developer testing and hence are undocumented.

Virtual Token Create and Add Failures

2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 : Unable to add VToken 4/8 to table : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 : Unable to start VToken 4/8 : RC_GENERAL_ERROR
2012 Feb 29 12:05:01 myLuna  local5 err  NTLS [1234]: error : 0xc0000002 : Unable to initialize VToken 4/8 : RC_GENERAL_ERROR

These messages indicate a failure to complete an intended operation on a virtual token within NTLS.