Skip to content

Commit a8b082a

Browse files
TheLastCicadaTheLastCicada
committed
perf: cut cold-start time from ~16 min to ~2 min
Lower scheduler tick for governance and default-org sync tasks from 300s to 30s, parallelize per-org subscribe loop with Promise.allSettled, quiet per-tick log spam at INFO level (demote "nothing to do" messages to DEBUG, make "Successfully synced" lines change-aware), add rate-limited heartbeat with store IDs for DataLayer correlation, remove redundant GovernanceV2.sync from v1 task, align sync-picklists-v2 default to 30s, add v1 governance success logging, and introduce DEFAULT_ORGANIZATIONS_SYNC_TASK_INTERVAL config key.
1 parent f43aaa9 commit a8b082a

19 files changed

Lines changed: 222 additions & 89 deletions

‎README.md‎

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -269,9 +269,10 @@ In the `CHIA_ROOT` directory (usually `~/.chia/mainnet` on Linux), CADT will add
269269
* **AUTO_MIRROR_EXTERNAL_STORES**: When set to true (the default), CADT will automatically create mirrors for each store you are subscribed to. Mirroring all subscriptions using the `DATALAYER_FILE_SERVER_URL` will make the entire CADT network more resilient and distributed. Note: `DATALAYER_FILE_SERVER_URL` must also be set to a valid URL or IP address for mirrors to be created. Both settings are required for external store mirroring to function.
270270
* **LOG_LEVEL**: Controls verbosity of logging. Common settings are `info` and `debug`. Setting to `silly` will log all queries.
271271
* **TASKS**: Section for configuring sync intervals.
272-
* **GOVERNANCE_SYNC_TASK_INTERVAL**: Syncs new organizations from the governance node. Default 86400 seconds.
273-
* **ORGANIZATION_META_SYNC_TASK_INTERVAL**: Syncs organization data from the blockchain. Default 300 seconds.
274-
* **PICKLIST_SYNC_TASK_INTERVAL**: Syncs picklist from the governance node. Default 60 seconds.
272+
* **GOVERNANCE_SYNC_TASK_INTERVAL**: Syncs picklist, orgList, and glossary from the governance node. Default 30 seconds.
273+
* **DEFAULT_ORGANIZATIONS_SYNC_TASK_INTERVAL**: Subscribes to and imports default organizations published by the governance node. Default 30 seconds.
274+
* **ORGANIZATION_META_SYNC_TASK_INTERVAL**: Refreshes metadata for already-imported organizations. Default 300 seconds.
275+
* **PICKLIST_SYNC_TASK_INTERVAL**: Syncs picklist from the governance node. Default 30 seconds.
275276
* **MIRROR_CHECK_TASK_INTERVAL**: Checks if our DataLayer is advertising our `DATALAYER_FILE_SERVER_URL` as a mirror for all subscriptions when `AUTO_MIRROR_EXTERNAL_STORES` is true. Default 86460 seconds.
276277
* **VALIDATE_ORGANIZATION_TABLE_TASK_INTERVAL**: Validates the organization table periodically. Default 1800 seconds.
277278
* **REQUEST_CONTENT_LIMITS**: Section for configuring request size limits to prevent denial-of-service attacks. These limits control the maximum array lengths in API requests.

‎docker-compose-example.yml‎

Lines changed: 3 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -31,9 +31,10 @@ services:
3131
- LOG_LEVEL=info
3232

3333
# APP.TASKS settings
34-
- GOVERNANCE_SYNC_TASK_INTERVAL=300
34+
- GOVERNANCE_SYNC_TASK_INTERVAL=30
35+
- DEFAULT_ORGANIZATIONS_SYNC_TASK_INTERVAL=30
3536
- ORGANIZATION_META_SYNC_TASK_INTERVAL=300
36-
- PICKLIST_SYNC_TASK_INTERVAL=60
37+
- PICKLIST_SYNC_TASK_INTERVAL=30
3738
- MIRROR_CHECK_TASK_INTERVAL=86460
3839
- VALIDATE_ORGANIZATION_TABLE_TASK_INTERVAL=1800
3940

‎docker-entrypoint.sh‎

Lines changed: 1 addition & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -109,6 +109,7 @@ update_app_config "LOG_LEVEL" '.LOG_LEVEL'
109109

110110
# APP.TASKS section (shared)
111111
update_app_config "GOVERNANCE_SYNC_TASK_INTERVAL" '.TASKS.GOVERNANCE_SYNC_TASK_INTERVAL'
112+
update_app_config "DEFAULT_ORGANIZATIONS_SYNC_TASK_INTERVAL" '.TASKS.DEFAULT_ORGANIZATIONS_SYNC_TASK_INTERVAL'
112113
update_app_config "ORGANIZATION_META_SYNC_TASK_INTERVAL" '.TASKS.ORGANIZATION_META_SYNC_TASK_INTERVAL'
113114
update_app_config "PICKLIST_SYNC_TASK_INTERVAL" '.TASKS.PICKLIST_SYNC_TASK_INTERVAL'
114115
update_app_config "MIRROR_CHECK_TASK_INTERVAL" '.TASKS.MIRROR_CHECK_TASK_INTERVAL'

‎src/datalayer/persistance.js‎

Lines changed: 1 addition & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -967,7 +967,7 @@ const subscribeToStoreOnDataLayer = async (storeId) => {
967967
}
968968

969969
if (subscriptions.includes(storeId)) {
970-
logger.info(`Already subscribed to: ${storeId}`);
970+
logger.debug(`Already subscribed to: ${storeId}`);
971971
return true;
972972
}
973973

‎src/models/governance/governance.model.js‎

Lines changed: 44 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -137,8 +137,6 @@ class Governance extends Model {
137137
confirmed: true,
138138
});
139139
} else if (USE_SIMULATOR || USE_DEVELOPMENT_MODE) {
140-
// this block is just a fallback if the app gets through the upstream checks,
141-
// might be unnecessary
142140
logger.info('SIMULATOR/DEVELOPMENT MODE: Using sample picklist');
143141
updates.push({
144142
metaKey: 'pickList',
@@ -151,8 +149,36 @@ class Governance extends Model {
151149
);
152150
}
153151

152+
// Compare incoming values against existing rows to detect actual changes
153+
let changed = false;
154+
for (const update of updates) {
155+
const existing = await Governance.findOne({
156+
where: { metaKey: update.metaKey },
157+
raw: true,
158+
});
159+
if (!existing || existing.metaValue !== update.metaValue) {
160+
changed = true;
161+
break;
162+
}
163+
}
164+
154165
logger.debug('upserting governance data from governance body store');
155166
await Promise.all(updates.map(async (update) => Governance.upsert(update)));
167+
return { changed };
168+
}
169+
170+
static _lastHeartbeat = 0;
171+
172+
static _emitHeartbeat(stage, storeId, syncStatus) {
173+
const now = Date.now();
174+
if (now - Governance._lastHeartbeat < 60_000) return;
175+
Governance._lastHeartbeat = now;
176+
const statusStr = syncStatus
177+
? ` (generation ${syncStatus.generation ?? '?'}/${syncStatus.target_generation ?? '?'})`
178+
: '';
179+
logger.info(
180+
`[v1]: CADT is waiting for DataLayer to sync governance data: ${stage} store ${storeId}${statusStr}. Next check within 30s.`,
181+
);
156182
}
157183

158184
static async sync() {
@@ -203,9 +229,10 @@ class Governance extends Model {
203229
try {
204230
const bodyStoreSyncStatus = await datalayer.getDataLayerStoreSyncStatus(GOVERNANCE_BODY_ID);
205231
if (!isDlStoreSynced(bodyStoreSyncStatus?.sync_status)) {
206-
logger.info(
232+
logger.debug(
207233
`[v1]: governance body store ${GOVERNANCE_BODY_ID} not yet synced. Skipping sync, will retry on next task run.`,
208234
);
235+
Governance._emitHeartbeat('body', GOVERNANCE_BODY_ID, bodyStoreSyncStatus?.sync_status);
209236
return;
210237
}
211238
} catch (error) {
@@ -233,7 +260,12 @@ class Governance extends Model {
233260
logger.info(
234261
`[v1]: using legacy governance upsert method for governance store ${GOVERNANCE_BODY_ID}`,
235262
);
236-
await Governance.upsertGovernanceDownload(GOVERNANCE_BODY_ID, governanceData);
263+
const { changed } = await Governance.upsertGovernanceDownload(GOVERNANCE_BODY_ID, governanceData);
264+
if (changed) {
265+
logger.info('[v1]: Successfully synced legacy governance data');
266+
} else {
267+
logger.debug('[v1]: Legacy governance data unchanged, no update needed');
268+
}
237269
return;
238270
}
239271

@@ -268,9 +300,10 @@ class Governance extends Model {
268300
try {
269301
const versionedSyncStatus = await datalayer.getDataLayerStoreSyncStatus(versionedGovernanceStoreId);
270302
if (!isDlStoreSynced(versionedSyncStatus?.sync_status)) {
271-
logger.info(
303+
logger.debug(
272304
`[v1]: versioned governance store ${versionedGovernanceStoreId} not yet synced. Skipping sync, will retry on next task run.`,
273305
);
306+
Governance._emitHeartbeat('versioned', versionedGovernanceStoreId, versionedSyncStatus?.sync_status);
274307
return;
275308
}
276309
} catch (error) {
@@ -289,7 +322,12 @@ class Governance extends Model {
289322
false,
290323
);
291324

292-
await Governance.upsertGovernanceDownload(GOVERNANCE_BODY_ID, versionedGovernanceData);
325+
const { changed } = await Governance.upsertGovernanceDownload(GOVERNANCE_BODY_ID, versionedGovernanceData);
326+
if (changed) {
327+
logger.info('[v1]: Successfully synced versioned governance data');
328+
} else {
329+
logger.debug('[v1]: Versioned governance data unchanged, no update needed');
330+
}
293331
} catch (error) {
294332
logger.error(
295333
`[v1]: Error syncing governance data: ${error.message}. Cached governance data will be used until next task run.`,

‎src/models/v2/governance-v2.model.js‎

Lines changed: 44 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -113,8 +113,36 @@ class GovernanceV2 extends Model {
113113
);
114114
}
115115

116+
// Compare incoming values against existing rows to detect actual changes
117+
let changed = false;
118+
for (const update of updates) {
119+
const existing = await GovernanceV2.findOne({
120+
where: { meta_key: update.meta_key },
121+
raw: true,
122+
});
123+
if (!existing || existing.meta_value !== update.meta_value) {
124+
changed = true;
125+
break;
126+
}
127+
}
128+
116129
loggerV2.debug('[v2]: upserting governance data from governance body store');
117130
await Promise.all(updates.map(async (update) => GovernanceV2.upsert(update)));
131+
return { changed };
132+
}
133+
134+
static _lastHeartbeat = 0;
135+
136+
static _emitHeartbeat(stage, storeId, syncStatus) {
137+
const now = Date.now();
138+
if (now - GovernanceV2._lastHeartbeat < 60_000) return;
139+
GovernanceV2._lastHeartbeat = now;
140+
const statusStr = syncStatus
141+
? ` (generation ${syncStatus.generation ?? '?'}/${syncStatus.target_generation ?? '?'})`
142+
: '';
143+
loggerV2.info(
144+
`[v2]: CADT is waiting for DataLayer to sync governance data: ${stage} store ${storeId}${statusStr}. Next check within 30s.`,
145+
);
118146
}
119147

120148
/**
@@ -482,9 +510,10 @@ class GovernanceV2 extends Model {
482510
try {
483511
const bodyStoreSyncStatus = await datalayer.getDataLayerStoreSyncStatus(GOVERNANCE_BODY_ID);
484512
if (!isDlStoreSynced(bodyStoreSyncStatus?.sync_status)) {
485-
loggerV2.info(
513+
loggerV2.debug(
486514
`[v2]: governance body store ${GOVERNANCE_BODY_ID} not yet synced. Skipping sync, will retry on next task run.`,
487515
);
516+
GovernanceV2._emitHeartbeat('body', GOVERNANCE_BODY_ID, bodyStoreSyncStatus?.sync_status);
488517
return;
489518
}
490519
} catch (error) {
@@ -512,8 +541,12 @@ class GovernanceV2 extends Model {
512541
loggerV2.info(
513542
`[v2]: using legacy governance upsert method for governance store ${GOVERNANCE_BODY_ID}`,
514543
);
515-
await GovernanceV2.upsertGovernanceDownload(GOVERNANCE_BODY_ID, governanceData);
516-
loggerV2.info('[v2]: Successfully synced legacy governance data');
544+
const { changed } = await GovernanceV2.upsertGovernanceDownload(GOVERNANCE_BODY_ID, governanceData);
545+
if (changed) {
546+
loggerV2.info('[v2]: Successfully synced legacy governance data');
547+
} else {
548+
loggerV2.debug('[v2]: Legacy governance data unchanged, no update needed');
549+
}
517550
return;
518551
}
519552

@@ -549,9 +582,10 @@ class GovernanceV2 extends Model {
549582
try {
550583
const versionedSyncStatus = await datalayer.getDataLayerStoreSyncStatus(versionedGovernanceStoreId);
551584
if (!isDlStoreSynced(versionedSyncStatus?.sync_status)) {
552-
loggerV2.info(
585+
loggerV2.debug(
553586
`[v2]: versioned governance store ${versionedGovernanceStoreId} not yet synced. Skipping sync, will retry on next task run.`,
554587
);
588+
GovernanceV2._emitHeartbeat('versioned', versionedGovernanceStoreId, versionedSyncStatus?.sync_status);
555589
return;
556590
}
557591
} catch (error) {
@@ -570,8 +604,12 @@ class GovernanceV2 extends Model {
570604
false,
571605
);
572606

573-
await GovernanceV2.upsertGovernanceDownload(GOVERNANCE_BODY_ID, versionedGovernanceData);
574-
loggerV2.info('[v2]: Successfully synced versioned governance data');
607+
const { changed } = await GovernanceV2.upsertGovernanceDownload(GOVERNANCE_BODY_ID, versionedGovernanceData);
608+
if (changed) {
609+
loggerV2.info('[v2]: Successfully synced versioned governance data');
610+
} else {
611+
loggerV2.debug('[v2]: Versioned governance data unchanged, no update needed');
612+
}
575613
} catch (error) {
576614
loggerV2.error(
577615
`[v2]: Error syncing governance data: ${error.message}. Cached governance data will be used until next task run.`,

‎src/models/v2/organizations-v2.model.js‎

Lines changed: 2 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -1627,7 +1627,7 @@ class OrganizationsV2 extends Model {
16271627
try {
16281628
const syncStatus = await datalayer.getDataLayerStoreSyncStatus(orgUid);
16291629
if (!isDlStoreSynced(syncStatus?.sync_status)) {
1630-
loggerV2.info(
1630+
loggerV2.debug(
16311631
`[v2]: Skipping import of organization ${orgUid} - store not yet synced. Will retry on next task run.`,
16321632
);
16331633
return;
@@ -1689,7 +1689,7 @@ class OrganizationsV2 extends Model {
16891689
singletonStoreId,
16901690
);
16911691
if (!isDlStoreSynced(singletonSyncStatus?.sync_status)) {
1692-
loggerV2.info(
1692+
loggerV2.debug(
16931693
`[v2]: Skipping import of organization ${orgUid} - singleton store ${singletonStoreId} not yet synced. Will retry on next task run.`,
16941694
);
16951695
return;

‎src/tasks/sync-default-organizations-v2.js‎

Lines changed: 46 additions & 28 deletions
Original file line numberDiff line numberDiff line change
@@ -10,6 +10,8 @@ import { getConfig } from '../utils/config-loader.js';
1010

1111
const CONFIG = getConfig().APP;
1212

13+
let lastHeartbeat = 0;
14+
1315
const task = new Task('sync-default-organizations-v2', async () => {
1416
try {
1517
await assertDataLayerAvailable();
@@ -25,6 +27,9 @@ const task = new Task('sync-default-organizations-v2', async () => {
2527
const defaultOrgList = await getDefaultOrganizationListV2();
2628
const userDeletedOrgs = await MetaV2.getUserDeletedOrgUids();
2729

30+
const pending = [];
31+
const imported = [];
32+
2833
for (const { orgUid } of defaultOrgList) {
2934
if (userDeletedOrgs?.includes(orgUid)) {
3035
loggerV2.verbose(
@@ -39,52 +44,65 @@ const task = new Task('sync-default-organizations-v2', async () => {
3944
});
4045

4146
if (!organization) {
47+
pending.push(orgUid);
48+
} else {
49+
imported.push(orgUid);
50+
}
51+
}
52+
53+
// Emit rate-limited heartbeat while orgs are still waiting
54+
if (pending.length > 0) {
55+
const now = Date.now();
56+
if (now - lastHeartbeat >= 60_000) {
57+
lastHeartbeat = now;
58+
const sample = pending.slice(0, 5).map((id) => `${id.slice(0, 8)}...`);
59+
const extra = pending.length > 5 ? `, ... +${pending.length - 5} more` : '';
60+
loggerV2.info(
61+
`[v2]: CADT is waiting for DataLayer to sync default organization stores: ${imported.length} imported, ${pending.length} waiting [${sample.join(', ')}${extra}]. Next check within 30s.`,
62+
);
63+
}
64+
}
65+
66+
// Fan out imports in parallel
67+
const results = await Promise.allSettled(
68+
pending.map(async (orgUid) => {
4269
loggerV2.debug(
4370
`[v2]: default organization ${orgUid} was NOT found in the organizations table. running the import process to correct`,
4471
);
45-
try {
46-
await OrganizationsV2.importOrganization(orgUid);
47-
// Verify the org was actually created (importOrganization may return early
48-
// if store is not synced yet, without throwing an error)
49-
const imported = await OrganizationsV2.findOne({
50-
where: { org_uid: orgUid },
51-
raw: true,
52-
});
53-
if (imported) {
54-
loggerV2.info(`[v2]: Successfully imported default organization ${orgUid}`);
55-
} else {
56-
loggerV2.debug(
57-
`[v2]: Import of default organization ${orgUid} deferred - store may still be syncing. Will retry on next task run.`,
58-
);
59-
}
60-
} catch (importError) {
61-
// Log error but continue to next org - this org will be retried on next task run
62-
// This prevents one slow/failed import from blocking all other orgs
63-
loggerV2.warn(
64-
`[v2]: Failed to import default organization ${orgUid}: ${importError.message}. Will retry on next task run.`,
72+
await OrganizationsV2.importOrganization(orgUid);
73+
const importedOrg = await OrganizationsV2.findOne({
74+
where: { org_uid: orgUid },
75+
raw: true,
76+
});
77+
if (importedOrg) {
78+
loggerV2.info(`[v2]: Successfully imported default organization ${orgUid}`);
79+
} else {
80+
loggerV2.debug(
81+
`[v2]: Import of default organization ${orgUid} deferred - store may still be syncing. Will retry on next task run.`,
6582
);
6683
}
67-
} else {
68-
const orgReduced = { ...organization };
69-
delete orgReduced.icon;
70-
delete orgReduced.metadata;
71-
loggerV2.debug(
72-
`sync default orgs task found the following organization data associated with default org (icon and meta removed for compactness) ${orgUid}:\n${JSON.stringify(orgReduced)}`,
84+
}),
85+
);
86+
87+
for (const result of results) {
88+
if (result.status === 'rejected') {
89+
loggerV2.warn(
90+
`[v2]: Failed to import a default organization: ${result.reason?.message || result.reason}. Will retry on next task run.`,
7391
);
7492
}
7593
}
7694
}
7795
} catch (error) {
7896
loggerV2.error(
7997
`[v2]: failed to validate default organization records and subscriptions. Error ${error.message}. ` +
80-
`Retrying in ${CONFIG?.TASKS?.ORGANIZATION_META_SYNC_TASK_INTERVAL || 300} seconds`,
98+
`Retrying in ${CONFIG?.TASKS?.DEFAULT_ORGANIZATIONS_SYNC_TASK_INTERVAL || 30} seconds`,
8199
);
82100
}
83101
});
84102

85103
const job = new SimpleIntervalJob(
86104
{
87-
seconds: CONFIG?.TASKS?.ORGANIZATION_META_SYNC_TASK_INTERVAL || 300,
105+
seconds: CONFIG?.TASKS?.DEFAULT_ORGANIZATIONS_SYNC_TASK_INTERVAL || 30,
88106
runImmediately: true,
89107
},
90108
task,

0 commit comments

Comments
 (0)