From 54da3544991fc2c1aa80d13e9163fd341e1fdd08 Mon Sep 17 00:00:00 2001 From: Which Node Date: Sat, 30 Nov 2024 09:39:16 -0700 Subject: [PATCH 01/17] Add some debug output to the validator handle code path --- api/src/ol/validators/validators.service.ts | 6 +++++- 1 file changed, 5 insertions(+), 1 deletion(-) diff --git a/api/src/ol/validators/validators.service.ts b/api/src/ol/validators/validators.service.ts index ee22a790..d58b9417 100644 --- a/api/src/ol/validators/validators.service.ts +++ b/api/src/ol/validators/validators.service.ts @@ -76,10 +76,14 @@ export class ValidatorsService { public async getValidatorsHandlers(): Promise> { if (this.cacheEnabled) { + this.logger.debug('Cache is enabled') const cacheHandlersString = await this.getFromCache(VALIDATORS_HANDLERS_CACHE_KEY); - return cacheHandlersString + this.logger.debug(`Fetched this from redis: ${cacheHandlersString}`) + let result = cacheHandlersString ? new Map(Object.entries(cacheHandlersString)) : new Map(); + this.logger.debug(`returning this: ${result}`) + return result; } let handlers = new Map(); From f66950556f667c8f99efa0600a89bc7e40502d82 Mon Sep 17 00:00:00 2001 From: Which Node Date: Sat, 30 Nov 2024 09:43:44 -0700 Subject: [PATCH 02/17] Trigger container build --- .github/workflows/build-api-container.yml | 1 + 1 file changed, 1 insertion(+) diff --git a/.github/workflows/build-api-container.yml b/.github/workflows/build-api-container.yml index 4d6ac0f9..f65e33a0 100644 --- a/.github/workflows/build-api-container.yml +++ b/.github/workflows/build-api-container.yml @@ -8,6 +8,7 @@ on: branches: - main - build-test + - validator-cache-debugging jobs: build: From 71b5d78f5a94e19c9dbb57780c637c54e00831fa Mon Sep 17 00:00:00 2001 From: Which Node Date: Sat, 30 Nov 2024 10:12:09 -0700 Subject: [PATCH 03/17] Log payload --- api/src/ol/validators/validators.service.ts | 4 ++-- 1 file changed, 2 insertions(+), 2 deletions(-) diff --git a/api/src/ol/validators/validators.service.ts b/api/src/ol/validators/validators.service.ts index d58b9417..834425f0 100644 --- a/api/src/ol/validators/validators.service.ts +++ b/api/src/ol/validators/validators.service.ts @@ -78,11 +78,11 @@ export class ValidatorsService { if (this.cacheEnabled) { this.logger.debug('Cache is enabled') const cacheHandlersString = await this.getFromCache(VALIDATORS_HANDLERS_CACHE_KEY); - this.logger.debug(`Fetched this from redis: ${cacheHandlersString}`) + this.logger.debug(`Fetched this from redis: ${JSON.stringify(cacheHandlersString)}`) let result = cacheHandlersString ? new Map(Object.entries(cacheHandlersString)) : new Map(); - this.logger.debug(`returning this: ${result}`) + this.logger.debug(`returning this: ${JSON.stringify(result)}`) return result; } From 7606c1809ee4f1704f91bcdc9cb91b2c74b754ad Mon Sep 17 00:00:00 2001 From: Which Node Date: Sat, 30 Nov 2024 13:45:43 -0700 Subject: [PATCH 04/17] Add more logging --- api/src/ol/validators/validators.service.ts | 12 +++++++++--- 1 file changed, 9 insertions(+), 3 deletions(-) diff --git a/api/src/ol/validators/validators.service.ts b/api/src/ol/validators/validators.service.ts index 834425f0..1f6d181a 100644 --- a/api/src/ol/validators/validators.service.ts +++ b/api/src/ol/validators/validators.service.ts @@ -78,10 +78,16 @@ export class ValidatorsService { if (this.cacheEnabled) { this.logger.debug('Cache is enabled') const cacheHandlersString = await this.getFromCache(VALIDATORS_HANDLERS_CACHE_KEY); + // NOTE: cacheHandlersString is NOT a string (it is an Object) this.logger.debug(`Fetched this from redis: ${JSON.stringify(cacheHandlersString)}`) - let result = cacheHandlersString - ? new Map(Object.entries(cacheHandlersString)) - : new Map(); + let result:Map = new Map(); + if (cacheHandlersString) { + result = new Map(Object.entries(cacheHandlersString)) + this.logger.debug('Created map from entries') + } else { + result = new Map(); + this.logger.debug('Created empty map') + } this.logger.debug(`returning this: ${JSON.stringify(result)}`) return result; } From 0ab7fd63b582e960fb06d29efe52b19af7bc1b11 Mon Sep 17 00:00:00 2001 From: Which Node Date: Sat, 30 Nov 2024 14:06:59 -0700 Subject: [PATCH 05/17] Log cache fetch entries --- api/src/ol/validators/validators.service.ts | 1 + 1 file changed, 1 insertion(+) diff --git a/api/src/ol/validators/validators.service.ts b/api/src/ol/validators/validators.service.ts index 1f6d181a..37e4857f 100644 --- a/api/src/ol/validators/validators.service.ts +++ b/api/src/ol/validators/validators.service.ts @@ -82,6 +82,7 @@ export class ValidatorsService { this.logger.debug(`Fetched this from redis: ${JSON.stringify(cacheHandlersString)}`) let result:Map = new Map(); if (cacheHandlersString) { + this.logger.debug(`Entries are: ${JSON.stringify(Object.entries(cacheHandlersString))}`) result = new Map(Object.entries(cacheHandlersString)) this.logger.debug('Created map from entries') } else { From 563f9d45e246d3b5ad2ee4f64b60b2b7bc6540a5 Mon Sep 17 00:00:00 2001 From: Which Node Date: Sat, 30 Nov 2024 15:07:34 -0700 Subject: [PATCH 06/17] Log cache fetch entries --- api/src/ol/validators/validators.service.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/api/src/ol/validators/validators.service.ts b/api/src/ol/validators/validators.service.ts index 37e4857f..ddf153fb 100644 --- a/api/src/ol/validators/validators.service.ts +++ b/api/src/ol/validators/validators.service.ts @@ -84,7 +84,7 @@ export class ValidatorsService { if (cacheHandlersString) { this.logger.debug(`Entries are: ${JSON.stringify(Object.entries(cacheHandlersString))}`) result = new Map(Object.entries(cacheHandlersString)) - this.logger.debug('Created map from entries') + this.logger.debug(`Created map from entries: ${JSON.stringify(result)}`) } else { result = new Map(); this.logger.debug('Created empty map') From 54462aef0aa629e2804ba457573ba94a0f22cc99 Mon Sep 17 00:00:00 2001 From: Which Node Date: Sat, 30 Nov 2024 17:55:12 -0700 Subject: [PATCH 07/17] Log cache fetch entries --- api/src/ol/validators/validators.service.ts | 9 +++++---- 1 file changed, 5 insertions(+), 4 deletions(-) diff --git a/api/src/ol/validators/validators.service.ts b/api/src/ol/validators/validators.service.ts index ddf153fb..b09ff13b 100644 --- a/api/src/ol/validators/validators.service.ts +++ b/api/src/ol/validators/validators.service.ts @@ -80,11 +80,12 @@ export class ValidatorsService { const cacheHandlersString = await this.getFromCache(VALIDATORS_HANDLERS_CACHE_KEY); // NOTE: cacheHandlersString is NOT a string (it is an Object) this.logger.debug(`Fetched this from redis: ${JSON.stringify(cacheHandlersString)}`) - let result:Map = new Map(); + let result:Map = new Map([['bad', 'data']]); if (cacheHandlersString) { - this.logger.debug(`Entries are: ${JSON.stringify(Object.entries(cacheHandlersString))}`) - result = new Map(Object.entries(cacheHandlersString)) - this.logger.debug(`Created map from entries: ${JSON.stringify(result)}`) + let entries = Object.entries(cacheHandlersString); + this.logger.debug(`Entries are: ${entries}, ${JSON.stringify(entries)}`) + result = new Map(entries) + this.logger.debug(`Created map from entries: ${result}, ${JSON.stringify(result)}`) } else { result = new Map(); this.logger.debug('Created empty map') From 91b106d0afa18d69db881743d815f4df021844df Mon Sep 17 00:00:00 2001 From: Which Node Date: Sat, 30 Nov 2024 18:31:31 -0700 Subject: [PATCH 08/17] Way more logging --- api/src/ol/validators/validators.service.ts | 7 +++++-- 1 file changed, 5 insertions(+), 2 deletions(-) diff --git a/api/src/ol/validators/validators.service.ts b/api/src/ol/validators/validators.service.ts index b09ff13b..39539307 100644 --- a/api/src/ol/validators/validators.service.ts +++ b/api/src/ol/validators/validators.service.ts @@ -79,11 +79,12 @@ export class ValidatorsService { this.logger.debug('Cache is enabled') const cacheHandlersString = await this.getFromCache(VALIDATORS_HANDLERS_CACHE_KEY); // NOTE: cacheHandlersString is NOT a string (it is an Object) - this.logger.debug(`Fetched this from redis: ${JSON.stringify(cacheHandlersString)}`) + this.logger.debug(`Fetched this from redis: ${cacheHandlersString}, ${JSON.stringify(cacheHandlersString)}`) let result:Map = new Map([['bad', 'data']]); if (cacheHandlersString) { let entries = Object.entries(cacheHandlersString); - this.logger.debug(`Entries are: ${entries}, ${JSON.stringify(entries)}`) + this.logger.debug(`Entries have type: ${typeof entries} and is an array: ${Array.isArray(entries)}`) + this.logger.debug(`and the first element is: ${entries[0]} and are: ${entries}, ${JSON.stringify(entries)}`) result = new Map(entries) this.logger.debug(`Created map from entries: ${result}, ${JSON.stringify(result)}`) } else { @@ -97,10 +98,12 @@ export class ValidatorsService { let handlers = new Map(); try { handlers = await this.loadValidatorHandles(); + this.logger.debug(`Loaded validator handles: ${handlers}, ${JSON.stringify(handlers)}`) } catch (error) { this.logger.error('Error loading validators handlers', error); } finally { const obj = Object.fromEntries(handlers); + this.logger.debug(`Storing validator handles: ${obj}, ${JSON.stringify(obj)}`) await redisClient.set(VALIDATORS_HANDLERS_CACHE_KEY, JSON.stringify(obj)); this.logger.log('Validators handlers cache updated'); } From b010396ed0d188fe067b1aa7e6b74131f5bdefce Mon Sep 17 00:00:00 2001 From: Which Node Date: Sat, 30 Nov 2024 18:34:24 -0700 Subject: [PATCH 09/17] Way more logging --- api/src/ol/validators/validators.service.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/api/src/ol/validators/validators.service.ts b/api/src/ol/validators/validators.service.ts index 39539307..880d9f47 100644 --- a/api/src/ol/validators/validators.service.ts +++ b/api/src/ol/validators/validators.service.ts @@ -86,7 +86,7 @@ export class ValidatorsService { this.logger.debug(`Entries have type: ${typeof entries} and is an array: ${Array.isArray(entries)}`) this.logger.debug(`and the first element is: ${entries[0]} and are: ${entries}, ${JSON.stringify(entries)}`) result = new Map(entries) - this.logger.debug(`Created map from entries: ${result}, ${JSON.stringify(result)}`) + this.logger.debug(`Created map from entries: ${result}, ${JSON.stringify(Array.from(result.entries()))}`) } else { result = new Map(); this.logger.debug('Created empty map') From ec30329d7ece6ca68d25e6122e1a96ed5b4d3243 Mon Sep 17 00:00:00 2001 From: Which Node Date: Sat, 30 Nov 2024 19:53:42 -0700 Subject: [PATCH 10/17] Log use of handles --- api/src/ol/validators/validators.service.ts | 10 ++++------ 1 file changed, 4 insertions(+), 6 deletions(-) diff --git a/api/src/ol/validators/validators.service.ts b/api/src/ol/validators/validators.service.ts index 880d9f47..ee4fff7e 100644 --- a/api/src/ol/validators/validators.service.ts +++ b/api/src/ol/validators/validators.service.ts @@ -79,19 +79,14 @@ export class ValidatorsService { this.logger.debug('Cache is enabled') const cacheHandlersString = await this.getFromCache(VALIDATORS_HANDLERS_CACHE_KEY); // NOTE: cacheHandlersString is NOT a string (it is an Object) - this.logger.debug(`Fetched this from redis: ${cacheHandlersString}, ${JSON.stringify(cacheHandlersString)}`) let result:Map = new Map([['bad', 'data']]); if (cacheHandlersString) { let entries = Object.entries(cacheHandlersString); - this.logger.debug(`Entries have type: ${typeof entries} and is an array: ${Array.isArray(entries)}`) - this.logger.debug(`and the first element is: ${entries[0]} and are: ${entries}, ${JSON.stringify(entries)}`) result = new Map(entries) - this.logger.debug(`Created map from entries: ${result}, ${JSON.stringify(Array.from(result.entries()))}`) } else { result = new Map(); - this.logger.debug('Created empty map') } - this.logger.debug(`returning this: ${JSON.stringify(result)}`) + this.logger.debug(`returning handles map with ${result.size} entries`) return result; } @@ -186,6 +181,7 @@ export class ValidatorsService { ); let handles = await this.getValidatorsHandlers(); + this.logger.debug(`handles map has ${handles.size} entries`) let allValidators = [...currentValidators, ...eligibleValidators]; return await Promise.all( allValidators.map(async (validator) => { @@ -196,6 +192,7 @@ export class ValidatorsService { const unlocked = Number(slowWallet?.unlocked); const addr = validator.address.toString('hex').toLocaleUpperCase(); const handle = handles.get(addr) || null; + this.logger.debug(`Setting handle as: ${handle}`) return new Validator({ inSet: validator.inSet, @@ -334,6 +331,7 @@ export class ValidatorsService { const eligible = await this.olService.getEligibleValidators(); const active = await this.olService.getValidatorSet(); const handles = await this.getValidatorsHandlers(); + this.logger.debug(`handles map has ${handles.size} entries`) const currentEpoch = await this.olService.aptosClient .getLedgerInfo() .then((info) => Number(info.epoch)); From 48ca266f583ff6e520948426845993381115def4 Mon Sep 17 00:00:00 2001 From: Which Node Date: Sun, 1 Dec 2024 08:24:51 -0700 Subject: [PATCH 11/17] Logging for validators caching --- api/src/ol/validators/validators.service.ts | 4 +++- 1 file changed, 3 insertions(+), 1 deletion(-) diff --git a/api/src/ol/validators/validators.service.ts b/api/src/ol/validators/validators.service.ts index ee4fff7e..28716ad5 100644 --- a/api/src/ol/validators/validators.service.ts +++ b/api/src/ol/validators/validators.service.ts @@ -64,12 +64,15 @@ export class ValidatorsService { if (this.cacheEnabled) { const cachedValidators = await this.getFromCache(VALIDATORS_CACHE_KEY); if (cachedValidators) { + this.logger.debug('Returning cached validators') return cachedValidators; } } const validators = await this.queryValidators(); await this.setCache('validators', validators); + this.logger.debug('Stored validators in cache') + this.logger.debug(`This data stored: ${JSON.stringify(validators)}`) return validators; } @@ -192,7 +195,6 @@ export class ValidatorsService { const unlocked = Number(slowWallet?.unlocked); const addr = validator.address.toString('hex').toLocaleUpperCase(); const handle = handles.get(addr) || null; - this.logger.debug(`Setting handle as: ${handle}`) return new Validator({ inSet: validator.inSet, From 447b8df981d3f3489baadacae1d133e7f6846655 Mon Sep 17 00:00:00 2001 From: Which Node Date: Sun, 1 Dec 2024 09:20:20 -0700 Subject: [PATCH 12/17] Logging for validators caching --- api/src/ol/validators/validators.service.ts | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/api/src/ol/validators/validators.service.ts b/api/src/ol/validators/validators.service.ts index 28716ad5..0c25e10a 100644 --- a/api/src/ol/validators/validators.service.ts +++ b/api/src/ol/validators/validators.service.ts @@ -70,7 +70,7 @@ export class ValidatorsService { } const validators = await this.queryValidators(); - await this.setCache('validators', validators); + await this.setCache(VALIDATORS_CACHE_KEY, validators); this.logger.debug('Stored validators in cache') this.logger.debug(`This data stored: ${JSON.stringify(validators)}`) @@ -194,6 +194,9 @@ export class ValidatorsService { const slowWallet = await this.olService.getSlowWallet(validator.address); const unlocked = Number(slowWallet?.unlocked); const addr = validator.address.toString('hex').toLocaleUpperCase(); + if (!handles.get(addr)) { + this.logger.debug(`handles miss for address ${addr}`) + } const handle = handles.get(addr) || null; return new Validator({ From 23a41a1c374e534a7839e86523c935007f3ca9a5 Mon Sep 17 00:00:00 2001 From: Which Node Date: Sun, 1 Dec 2024 11:15:59 -0700 Subject: [PATCH 13/17] Log cache in and out data --- api/src/ol/validators/validators.processor.ts | 1 + api/src/ol/validators/validators.service.ts | 1 + 2 files changed, 2 insertions(+) diff --git a/api/src/ol/validators/validators.processor.ts b/api/src/ol/validators/validators.processor.ts index 5fab7a8e..c04d48f7 100644 --- a/api/src/ol/validators/validators.processor.ts +++ b/api/src/ol/validators/validators.processor.ts @@ -110,6 +110,7 @@ export class ValidatorsProcessor extends WorkerHost { try { const validators = await this.validatorsService.queryValidators(); await redisClient.set(VALIDATORS_CACHE_KEY, JSON.stringify(validators)); + this.logger.debug(`Wrote this to the cache: ${JSON.stringify(validators)}`) const duration = Date.now() - start; this.logger.log(`Validators cache updated in ${duration}ms`); } catch (error) { diff --git a/api/src/ol/validators/validators.service.ts b/api/src/ol/validators/validators.service.ts index 0c25e10a..7a5bab03 100644 --- a/api/src/ol/validators/validators.service.ts +++ b/api/src/ol/validators/validators.service.ts @@ -65,6 +65,7 @@ export class ValidatorsService { const cachedValidators = await this.getFromCache(VALIDATORS_CACHE_KEY); if (cachedValidators) { this.logger.debug('Returning cached validators') + this.logger.debug(`Read this data from cache: ${JSON.stringify(cachedValidators)}`) return cachedValidators; } } From 4a97bb34b7f6d8a68a799325bf790ffee03de979 Mon Sep 17 00:00:00 2001 From: Which Node Date: Sun, 1 Dec 2024 12:09:46 -0700 Subject: [PATCH 14/17] Truncate log output --- api/src/ol/validators/validators.processor.ts | 2 +- api/src/ol/validators/validators.service.ts | 4 ++-- 2 files changed, 3 insertions(+), 3 deletions(-) diff --git a/api/src/ol/validators/validators.processor.ts b/api/src/ol/validators/validators.processor.ts index c04d48f7..94b06cf2 100644 --- a/api/src/ol/validators/validators.processor.ts +++ b/api/src/ol/validators/validators.processor.ts @@ -110,7 +110,7 @@ export class ValidatorsProcessor extends WorkerHost { try { const validators = await this.validatorsService.queryValidators(); await redisClient.set(VALIDATORS_CACHE_KEY, JSON.stringify(validators)); - this.logger.debug(`Wrote this to the cache: ${JSON.stringify(validators)}`) + this.logger.debug(`Wrote this to the cache: ${JSON.stringify(validators).slice(0, 200)}`) const duration = Date.now() - start; this.logger.log(`Validators cache updated in ${duration}ms`); } catch (error) { diff --git a/api/src/ol/validators/validators.service.ts b/api/src/ol/validators/validators.service.ts index 7a5bab03..9783910b 100644 --- a/api/src/ol/validators/validators.service.ts +++ b/api/src/ol/validators/validators.service.ts @@ -65,7 +65,7 @@ export class ValidatorsService { const cachedValidators = await this.getFromCache(VALIDATORS_CACHE_KEY); if (cachedValidators) { this.logger.debug('Returning cached validators') - this.logger.debug(`Read this data from cache: ${JSON.stringify(cachedValidators)}`) + this.logger.debug(`Read this data from cache: ${JSON.stringify(cachedValidators).slice(0, 200)}`) return cachedValidators; } } @@ -73,7 +73,7 @@ export class ValidatorsService { const validators = await this.queryValidators(); await this.setCache(VALIDATORS_CACHE_KEY, validators); this.logger.debug('Stored validators in cache') - this.logger.debug(`This data stored: ${JSON.stringify(validators)}`) + this.logger.debug(`This data written back: ${JSON.stringify(validators).slice(0, 200)}`) return validators; } From 14a790648836b7b1cae252fc932ccd63b0442975 Mon Sep 17 00:00:00 2001 From: Which Node Date: Sat, 14 Dec 2024 17:19:34 -0700 Subject: [PATCH 15/17] Control logging level from an env var --- api/src/main.ts | 22 +++++++++++++++++++-- api/src/ol/validators/validators.service.ts | 1 + 2 files changed, 21 insertions(+), 2 deletions(-) diff --git a/api/src/main.ts b/api/src/main.ts index 60e879c7..9c52032d 100644 --- a/api/src/main.ts +++ b/api/src/main.ts @@ -1,13 +1,31 @@ import 'dotenv/config'; -import { NestFactory } from '@nestjs/core'; +import process from 'node:process'; +import { NestFactory, LogLevel } from '@nestjs/core'; import { NestExpressApplication } from '@nestjs/platform-express'; import { AppModule } from './app/app.module.js'; import getConfig from './config/config.js'; +function makeLogLevelList(): LogLevel[] { + // From: https://github.com/nestjs/nest/blob/master/packages/common/services/logger.service.ts#L9 + const allLogLevels: LogLevel[] = ['verbose', 'debug', 'log', 'warn', 'error', 'fatal']; + // From: https://stackoverflow.com/a/78585135/1701505 + const levels = allLogLevels.slice( + // TODO: possibly the env var shoud come via dotenv, or Config? + allLogLevels.indexOf((process.env.NESTJS_LOG_LEVEL || 'log') as LogLevel), + allLogLevels.length, + ); + return levels; +} + async function bootstrap() { const config = getConfig(); - const app = await NestFactory.create(AppModule); + const app = await NestFactory.create( + AppModule, + { + logger: makeLogLevelList() + } + ); app.enableShutdownHooks(); diff --git a/api/src/ol/validators/validators.service.ts b/api/src/ol/validators/validators.service.ts index 9783910b..68fcab5f 100644 --- a/api/src/ol/validators/validators.service.ts +++ b/api/src/ol/validators/validators.service.ts @@ -476,6 +476,7 @@ export class ValidatorsService { async loadValidatorHandles(): Promise> { if (!this.validatorHandlesUrl) { + this.logger.warn('Validator handles URL is not configured') return new Map(); } From 4bb935c1357760ecf00081aa9a6e832a9513d797 Mon Sep 17 00:00:00 2001 From: Which Node Date: Sat, 14 Dec 2024 19:50:26 -0700 Subject: [PATCH 16/17] Fix build --- api/src/main.ts | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/api/src/main.ts b/api/src/main.ts index 9c52032d..f7f65fac 100644 --- a/api/src/main.ts +++ b/api/src/main.ts @@ -1,6 +1,7 @@ import 'dotenv/config'; import process from 'node:process'; -import { NestFactory, LogLevel } from '@nestjs/core'; +import { NestFactory } from '@nestjs/core'; +import { LogLevel } from '@nestjs/common'; import { NestExpressApplication } from '@nestjs/platform-express'; import { AppModule } from './app/app.module.js'; import getConfig from './config/config.js'; From 55858dda836d95525abe6c61dec83ee948b8f6a6 Mon Sep 17 00:00:00 2001 From: Which Node Date: Thu, 19 Dec 2024 12:53:34 -0700 Subject: [PATCH 17/17] Disable CI build on PR branch --- .github/workflows/build-api-container.yml | 1 - 1 file changed, 1 deletion(-) diff --git a/.github/workflows/build-api-container.yml b/.github/workflows/build-api-container.yml index f65e33a0..4d6ac0f9 100644 --- a/.github/workflows/build-api-container.yml +++ b/.github/workflows/build-api-container.yml @@ -8,7 +8,6 @@ on: branches: - main - build-test - - validator-cache-debugging jobs: build: