Skip to content

ARSN-495: KMIP retries #2397

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
bert-e merged 5 commits into from
May 21, 2025
Merged

ARSN-495: KMIP retries #2397

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
5 commits
Select commit Hold shift + click to select a range
9a60325
ARSN-495: Retry internal thales session timeout
BourgoisMickael May 19, 2025
9e901f2
ARSN-495: Replace logger.error with logger.warn
BourgoisMickael May 19, 2025
576f0e9
ARSN-495: Implement retry and unhealthy hosts
BourgoisMickael May 19, 2025
c0d6cd8
ARSN-495: Print error msg
BourgoisMickael May 19, 2025
0ef69d3
ARSN-495: Bump version
BourgoisMickael May 19, 2025
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
34 changes: 23 additions & 11 deletions lib/network/kmip/Client.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -231,6 +231,9 @@ function _queryOperationsAndObjects(client: any, logger: werelogs.Logger, cb: an
{ vendorIdentification: client.vendorIdentification,
kmip: kmipLog });
}
// flag handshake as done, so if the connection is closed and reconnected
// another handshake won't be done as we already have the server's info
client.kmip.handshakeDone = true;
return cb();
});
}
Expand Down Expand Up @@ -336,7 +339,8 @@ export default class Client implements KMSInterface {
kmipMsg(operation, keyIdentifier,
'Server did not return the expected identifier')
);
logger.error(`KMIP::${operation}`,
// warn level to avoid dumping debug and trace logs on retryable errors
Comment thread
anurag4DSB marked this conversation as resolved.
logger.warn(`KMIP::${operation}`,
{ error, uniqueIdentifier, keyIdentifier });
return error;
}
Expand All @@ -357,7 +361,8 @@ export default class Client implements KMSInterface {
KMIP.TextString('Unique Identifier', keyIdentifier),
], (error, response) => {
if (error) {
logger.error('KMIP::_activateBucketKey',
// warn level to avoid dumping debug and trace logs on retryable errors
logger.warn('KMIP::_activateBucketKey',
{ error,
serverInformation: this.serverInformation });
return cb(error);
Expand Down Expand Up @@ -401,7 +406,8 @@ export default class Client implements KMSInterface {
KMIP.Structure('Template-Attribute', attributes),
], (error, response) => {
if (error) {
logger.error('KMIP::createBucketKey',
// warn level to avoid dumping debug and trace logs on retryable errors
logger.warn('KMIP::createBucketKey',
{ error,
serverInformation: this.serverInformation });
return cb(error);
Expand All @@ -416,7 +422,8 @@ export default class Client implements KMSInterface {
kmipMsg('Create', bucketName,
'Server created an object of wrong type')
);
logger.error('KMIP::createBucketKey',
// warn level to avoid dumping debug and trace logs on retryable errors
logger.warn('KMIP::createBucketKey',
{ error, createdObjectType });
return cb(error);
}
Expand Down Expand Up @@ -448,7 +455,8 @@ export default class Client implements KMSInterface {
]),
], (error, response) => {
if (error) {
logger.error('KMIP::_revokeBucketKey',
// warn level to avoid dumping debug and trace logs on retryable errors
logger.warn('KMIP::_revokeBucketKey',
{ error,
serverInformation: this.serverInformation });
return cb(error);
Expand All @@ -469,7 +477,8 @@ export default class Client implements KMSInterface {
return this._revokeBucketKey(bucketKeyId, logger, err => {
if (err) {
const error = arsenalErrorKMIP(err);
logger.error('KMIP::destroyBucketKey: revocation failed',
// warn level to avoid dumping debug and trace logs on retryable errors
logger.warn('KMIP::destroyBucketKey: revocation failed',
{ error,
serverInformation: this.serverInformation });
return cb(error);
Expand All @@ -479,7 +488,8 @@ export default class Client implements KMSInterface {
], (err, response) => {
if (err) {
const error = arsenalErrorKMIP(err);
logger.error('KMIP::destroyBucketKey',
// warn level to avoid dumping debug and trace logs on retryable errors
logger.warn('KMIP::destroyBucketKey',
{ error,
serverInformation: this.serverInformation });
return cb(error);
Expand Down Expand Up @@ -521,7 +531,8 @@ export default class Client implements KMSInterface {
KMIP.ByteString('IV/Counter/Nonce', CRYPTOGRAPHIC_DEFAULT_IV),
], (error, response) => {
if (error) {
logger.error('KMIP::cipherDataKey',
// warn level to avoid dumping debug and trace logs on retryable errors
logger.warn('KMIP::cipherDataKey',
{ error,
serverInformation: this.serverInformation });
return cb(error);
Expand Down Expand Up @@ -563,7 +574,8 @@ export default class Client implements KMSInterface {
KMIP.ByteString('IV/Counter/Nonce', CRYPTOGRAPHIC_DEFAULT_IV),
], (error, response) => {
if (error) {
logger.error('KMIP::decipherDataKey',
// warn level to avoid dumping debug and trace logs on retryable errors
logger.warn('KMIP::decipherDataKey',
{ error,
serverInformation: this.serverInformation });
return cb(error);
Expand All @@ -579,7 +591,7 @@ export default class Client implements KMSInterface {
// the bucket does not have to exist, just passing a common bucket name here
this.createBucketKey('kmip-healthcheck-test-bucket', logger, (err, bucketKeyId) => {
if (err) {
logger.error('KMIP::healthcheck: failure to create a test bucket key', {
logger.warn('KMIP::healthcheck: failure to create a test bucket key', {
error: err, kmip: kmipLog,
});
return cb(err);
Expand All @@ -588,7 +600,7 @@ export default class Client implements KMSInterface {
{ kmip: kmipLog });
this.destroyBucketKey(bucketKeyId, logger, err => {
if (err) {
logger.error('KMIP::healthcheck: failure to remove the test bucket key', {
logger.warn('KMIP::healthcheck: failure to remove the test bucket key', {
bucketKeyId,
error: err,
kmip: kmipLog,
Expand Down
195 changes: 189 additions & 6 deletions lib/network/kmip/ClusterClient.ts
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -5,13 +5,44 @@ import TTLVCodec from './codec/ttlv';
import TlsTransport from './transport/tls';
import KMIPClient, { KmipClientOptions } from './Client';
import { KmsBackend, KMSInterface, KmsType } from '../KMSInterface';
import type { Logger } from 'werelogs';
import { Logger } from 'werelogs';
import async from 'async';
import { ArsenalError, errorInstances } from '../../errors';
import { kmipMsg } from './errorMapping';

interface UnhealthyClient {
client: KMIPClient,
healthcheckTimeout: ReturnType<typeof setTimeout>,
};

/** Array without last item */
type ArrayPopped<Type extends unknown[]> = Type extends [...infer R, unknown] ? R : never;
/** Array's last item */
type ArrayLast<Type extends unknown[]> = Type extends [...unknown[], infer R] ? R : never

interface actions {
createBucketKey: Parameters<ClusterClient['createBucketKey']>;
destroyBucketKey: Parameters<ClusterClient['destroyBucketKey']>;
cipherDataKey: Parameters<ClusterClient['cipherDataKey']>;
decipherDataKey: Parameters<ClusterClient['decipherDataKey']>;
healthcheck: Parameters<ClusterClient['healthcheck']>;
};

interface ClusterClientOptions {
logger: Logger;
retries?: number;
};

const UNHEALTHY_DURATION = 30_000; // 30s

export default class ClusterClient implements KMSInterface {
/** Healthy clients */
private readonly clients: KMIPClient[];
private readonly unhealthyClients: UnhealthyClient[] = [];
private roundRobinIndex = 0;
public readonly backend: KmsBackend<KmsType.external>;
private readonly logger: Logger;
private readonly retries: number;

/**
* Construct a high level cluster of KMIP drivers suitable for cloudserver
Expand All @@ -36,7 +67,7 @@ export default class ClusterClient implements KMSInterface {
* defaults to TlsTransport
*/
constructor(
options: KmipClientOptions,
options: KmipClientOptions & ClusterClientOptions,
CodecClass: any,
TransportClass: any,
) {
Expand All @@ -47,6 +78,9 @@ export default class ClusterClient implements KMSInterface {
TransportClass || TlsTransport,
));
this.backend = this.clients[0].backend;
this.logger = options.logger;
// if retries is not configured, we retry as much host there are in the cluster
this.retries = typeof options.retries === 'number' ? options.retries : this.clients.length - 1;
}

next() {
Expand All @@ -56,25 +90,174 @@ export default class ClusterClient implements KMSInterface {
return this.clients[this.roundRobinIndex++];
}

checkUnhealthyClient(unhealthyClient: UnhealthyClient) {
const client = unhealthyClient.client;
const healthyIndex = this.clients.indexOf(client);
if (healthyIndex === -1) {
this.clients.push(client);
} else {
// should not happen (S3C-9956)
this.logger.warn('checkUnhealthyClient: already moved in healthy', { unhealthyHost: client.host });
Comment thread
anurag4DSB marked this conversation as resolved.
}

const unhealthyIndex = this.unhealthyClients.indexOf(unhealthyClient);
if (unhealthyIndex === -1) {
// should not happen (S3C-9956)
this.logger.warn('checkUnhealthyClient: already moved out of unhealthy', { unhealthyHost: client.host });
} else {
this.unhealthyClients.splice(unhealthyIndex, 1);
}
this.logger.info('kmip host healthy again', {
unhealthyHost: client.host,
unhealthy: this.unhealthyClients.length,
healthy: this.clients.length,
});
}

markUnhealthyClient(clientUsed: KMIPClient, logger: Logger, err: Error) {
logger.info('mark kmip host unhealthy', {
err,
msg: err?.toString?.(),
unhealthyHost: clientUsed.host,
unhealthy: this.unhealthyClients.length,
healthy: this.clients.length,
});
const index = this.clients.indexOf(clientUsed);
if (index === -1) {
// should not happen (S3C-9956)
logger.warn('already marked unhealthy');
return;
}
const spliced = this.clients.splice(index, 1);
const unhealthy = {
client: spliced[0],
healthcheckTimeout: setTimeout(() => this.checkUnhealthyClient(unhealthy), UNHEALTHY_DURATION),
};
this.unhealthyClients.push(unhealthy);
// the current index was removed
// decrease so next roundrobin uses current index again with new client
this.roundRobinIndex--;
}

callback<T extends keyof actions>(
clientUsed: KMIPClient,
funcName: T,
args: ArrayPopped<actions[T]>,
logger: ArrayLast<typeof args>,
originalCallback: ArrayLast<actions[T]>,
) {
let retries = 0;
const newCB = (err: (ArsenalError | Error | null) & { code?: number }, ...rest: any[]) => {
if (!err) {
// @ts-expect-error ts2556 typescript won't accept the spread on args array
return originalCallback(err, ...rest);
}
if (err.code && err.code >= 400 && err.code <= 499) {
// @ts-expect-error ts2556 typescript won't accept the spread on args array
return originalCallback(err, ...rest);
}

if (retries === this.retries) {
logger.warn(`kmip max retries reached: ${retries} / ${this.retries}`);
// @ts-expect-error ts2556 typescript won't accept the spread on args array
return originalCallback(err, ...rest);
}
retries++;

this.markUnhealthyClient(clientUsed, logger, err);

if (this.clients.length === 0) {
logger.warn('kmip cluster has no healthy hosts');
// @ts-expect-error ts2556 typescript won't accept the spread on args array
return originalCallback(err, ...rest);
}

const nextClient = this.next();
// @ts-expect-error ts2556 typescript won't accept the spread on args array
nextClient[funcName](...args, newCB);
return undefined;
};
return newCB;
}

createBucketKey(...args: Parameters<KMSInterface['createBucketKey']>) {
const originalCallback = args.pop() as ArrayLast<typeof args>;
const poppedArgs = args as unknown as ArrayPopped<typeof args>;
const logger = args[args.length - 1] as ArrayLast<typeof poppedArgs>;

if (this.clients.length === 0) {
logger.warn('kmip cluster has no healthy hosts');
return originalCallback(errorInstances.InternalError.customizeDescription(
kmipMsg('Create', args[0], `no healthy host in the cluster`)));
}

const client = this.next();
client.createBucketKey.apply(client, args);

client.createBucketKey(
...poppedArgs,
this.callback(client, 'createBucketKey', poppedArgs, logger, originalCallback),
);
return undefined;
}

destroyBucketKey(...args: Parameters<KMSInterface['destroyBucketKey']>) {
const originalCallback = args.pop() as ArrayLast<typeof args>;
const poppedArgs = args as unknown as ArrayPopped<typeof args>;
const logger = args[args.length - 1] as ArrayLast<typeof poppedArgs>;

if (this.clients.length === 0) {
logger.warn('kmip cluster has no healthy hosts');
return originalCallback(errorInstances.InternalError.customizeDescription(
kmipMsg('Destroy', args[0], `no healthy host in the cluster`)));
}

const client = this.next();
client.destroyBucketKey.apply(client, args);

client.destroyBucketKey(
...poppedArgs,
this.callback(client, 'destroyBucketKey', poppedArgs, logger, originalCallback),
);
return undefined;
}

cipherDataKey(...args: Parameters<KMSInterface['cipherDataKey']>) {
const originalCallback = args.pop() as ArrayLast<typeof args>;
const poppedArgs = args as unknown as ArrayPopped<typeof args>;
const logger = args[args.length - 1] as ArrayLast<typeof poppedArgs>;

if (this.clients.length === 0) {
logger.warn('kmip cluster has no healthy hosts');
return originalCallback(errorInstances.InternalError.customizeDescription(
kmipMsg('Encrypt', args[1], `no healthy host in the cluster`)));
}

const client = this.next();
client.cipherDataKey.apply(client, args);

client.cipherDataKey(
...poppedArgs,
this.callback(client, 'cipherDataKey', poppedArgs, logger, originalCallback),
);
return undefined;
}

decipherDataKey(...args: Parameters<KMSInterface['decipherDataKey']>) {
const originalCallback = args.pop() as ArrayLast<typeof args>;
const poppedArgs = args as unknown as ArrayPopped<typeof args>;
const logger = args[args.length - 1] as ArrayLast<typeof poppedArgs>;

if (this.clients.length === 0) {
logger.warn('kmip cluster has no healthy hosts');
return originalCallback(errorInstances.InternalError.customizeDescription(
kmipMsg('Decrypt', args[1], `no healthy host in the cluster`)));
}

const client = this.next();
client.decipherDataKey.apply(client, args);

client.decipherDataKey(
...poppedArgs,
this.callback(client, 'decipherDataKey', poppedArgs, logger, originalCallback),
);
return undefined;
}

clusterHealthcheck(logger: Logger, cb: (err: Error | null) => void) {
Expand Down
6 changes: 5 additions & 1 deletion lib/network/kmip/error-comparison.jsonc
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -33,8 +33,12 @@
"resultReason": "General Failure",
"resultMessage": [
"[NCERRInsufficientPermissions]: ",
// 24h idle token revoke is undocumented, but thales described us this behavior
// we asked them a tweaked lab to test with a 10m session.
// TLS session idle timeout (24h) - needs a new connection or no idle
"[NCERRUnauthorizedAccess]: Token has been revoked"
"[NCERRUnauthorizedAccess]: Token has been revoked",
// write after receiving above token revoked error
"[NCERRUnauthorizedAccess]: Invalid token"
Comment thread
BourgoisMickael marked this conversation as resolved.
]
}
}
Expand Down
Loading
Loading