feat(lid-mapping): enhance with enterprise-grade features
feat(lid-mapping): enhance with enterprise-grade features
This commit is contained in:
+743
-99
@@ -3,207 +3,851 @@ import type { LIDMapping, SignalKeyStoreWithTransaction } from '../Types'
|
||||
import type { ILogger } from '../Utils/logger'
|
||||
import { isHostedPnUser, isLidUser, isPnUser, jidDecode, jidNormalizedUser, WAJIDDomains } from '../WABinary'
|
||||
|
||||
// ============================================================================
|
||||
// CONFIGURATION
|
||||
// ============================================================================
|
||||
|
||||
/**
|
||||
* LID Mapping Store configuration
|
||||
* Configurable via environment variables with BAILEYS_LID_* prefix
|
||||
*/
|
||||
export interface LIDMappingConfig {
|
||||
/** Cache TTL in milliseconds (default: 3 days) */
|
||||
cacheTtlMs: number
|
||||
/** Maximum cache size (default: 50000 entries) */
|
||||
maxCacheSize: number
|
||||
/** Enable cache auto-purge (default: true) */
|
||||
cacheAutoPurge: boolean
|
||||
/** Update cache age on get (default: true) */
|
||||
updateAgeOnGet: boolean
|
||||
/** Enable Prometheus metrics (default: false) */
|
||||
enableMetrics: boolean
|
||||
/** Batch size for bulk operations (default: 100) */
|
||||
batchSize: number
|
||||
/** Retry attempts for failed operations (default: 3, max: 10) */
|
||||
retryAttempts: number
|
||||
/** Base retry delay in ms (default: 1000). Uses exponential backoff: delay * 2^(attempt-1) */
|
||||
retryDelayMs: number
|
||||
/** Enable debug logging (default: false) */
|
||||
debugLogging: boolean
|
||||
}
|
||||
|
||||
/**
|
||||
* Load configuration from environment variables
|
||||
* Includes bounds validation to prevent DoS from malicious values
|
||||
*/
|
||||
export function loadLIDMappingConfig(): LIDMappingConfig {
|
||||
// Helper to clamp values within safe bounds
|
||||
const clamp = (value: number, min: number, max: number): number =>
|
||||
Math.max(min, Math.min(max, isNaN(value) ? min : value))
|
||||
|
||||
const cacheTtlMs = parseInt(process.env.BAILEYS_LID_CACHE_TTL_MS || String(3 * 24 * 60 * 60 * 1000), 10)
|
||||
const maxCacheSize = parseInt(process.env.BAILEYS_LID_MAX_CACHE_SIZE || '50000', 10)
|
||||
const batchSize = parseInt(process.env.BAILEYS_LID_BATCH_SIZE || '100', 10)
|
||||
const retryAttempts = parseInt(process.env.BAILEYS_LID_RETRY_ATTEMPTS || '3', 10)
|
||||
const retryDelayMs = parseInt(process.env.BAILEYS_LID_RETRY_DELAY_MS || '1000', 10)
|
||||
|
||||
return {
|
||||
// Cache TTL: minimum 1 minute, maximum 30 days
|
||||
cacheTtlMs: clamp(cacheTtlMs, 60_000, 30 * 24 * 60 * 60 * 1000),
|
||||
// Cache size: minimum 100, maximum 1,000,000
|
||||
maxCacheSize: clamp(maxCacheSize, 100, 1_000_000),
|
||||
cacheAutoPurge: process.env.BAILEYS_LID_CACHE_AUTO_PURGE !== 'false',
|
||||
updateAgeOnGet: process.env.BAILEYS_LID_UPDATE_AGE_ON_GET !== 'false',
|
||||
enableMetrics: process.env.BAILEYS_LID_METRICS === 'true',
|
||||
// Batch size: minimum 1 (prevents infinite loop), maximum 1000
|
||||
batchSize: clamp(batchSize, 1, 1000),
|
||||
// Retry attempts: minimum 1, maximum 10
|
||||
retryAttempts: clamp(retryAttempts, 1, 10),
|
||||
// Retry delay: minimum 100ms, maximum 60 seconds
|
||||
retryDelayMs: clamp(retryDelayMs, 100, 60_000),
|
||||
debugLogging: process.env.BAILEYS_LID_DEBUG === 'true'
|
||||
}
|
||||
}
|
||||
|
||||
// ============================================================================
|
||||
// STATISTICS
|
||||
// ============================================================================
|
||||
|
||||
/**
|
||||
* Statistics for monitoring and debugging
|
||||
*/
|
||||
export interface LIDMappingStatistics {
|
||||
/** Total cache hits */
|
||||
cacheHits: number
|
||||
/** Total cache misses */
|
||||
cacheMisses: number
|
||||
/** Total database hits */
|
||||
dbHits: number
|
||||
/** Total database misses */
|
||||
dbMisses: number
|
||||
/** Total USync fetches */
|
||||
usyncFetches: number
|
||||
/** Total USync failures */
|
||||
usyncFailures: number
|
||||
/** Total mappings stored */
|
||||
mappingsStored: number
|
||||
/** Total invalid mappings rejected */
|
||||
invalidMappings: number
|
||||
/** Current cache size */
|
||||
cacheSize: number
|
||||
/** Cache hit rate (percentage) */
|
||||
cacheHitRate: number
|
||||
/** Total operations */
|
||||
totalOperations: number
|
||||
/** Failed operations */
|
||||
failedOperations: number
|
||||
/** Store creation timestamp */
|
||||
createdAt: number
|
||||
/** Last operation timestamp */
|
||||
lastOperationAt: number | null
|
||||
}
|
||||
|
||||
// ============================================================================
|
||||
// ERROR TYPES
|
||||
// ============================================================================
|
||||
|
||||
/**
|
||||
* Custom error for LID mapping operations
|
||||
*/
|
||||
export class LIDMappingError extends Error {
|
||||
constructor(
|
||||
message: string,
|
||||
public readonly code: LIDMappingErrorCode,
|
||||
public readonly details?: Record<string, unknown>
|
||||
) {
|
||||
super(message)
|
||||
this.name = 'LIDMappingError'
|
||||
}
|
||||
}
|
||||
|
||||
export enum LIDMappingErrorCode {
|
||||
INVALID_JID = 'INVALID_JID',
|
||||
INVALID_MAPPING = 'INVALID_MAPPING',
|
||||
DATABASE_ERROR = 'DATABASE_ERROR',
|
||||
USYNC_ERROR = 'USYNC_ERROR',
|
||||
CACHE_ERROR = 'CACHE_ERROR',
|
||||
DESTROYED = 'DESTROYED'
|
||||
}
|
||||
|
||||
// ============================================================================
|
||||
// MAIN CLASS
|
||||
// ============================================================================
|
||||
|
||||
/**
|
||||
* Enterprise-grade LID Mapping Store
|
||||
*
|
||||
* Features:
|
||||
* - Environment variable configuration
|
||||
* - LRU cache with configurable TTL and size
|
||||
* - Comprehensive statistics and metrics
|
||||
* - Batch operations for bulk mappings
|
||||
* - Retry logic for failed operations
|
||||
* - Proper resource cleanup
|
||||
* - Prometheus metrics integration
|
||||
*/
|
||||
export class LIDMappingStore {
|
||||
private readonly mappingCache = new LRUCache<string, string>({
|
||||
ttl: 3 * 24 * 60 * 60 * 1000, // 7 days
|
||||
ttlAutopurge: true,
|
||||
updateAgeOnGet: true
|
||||
})
|
||||
private readonly mappingCache: LRUCache<string, string>
|
||||
private readonly keys: SignalKeyStoreWithTransaction
|
||||
private readonly logger: ILogger
|
||||
private readonly config: LIDMappingConfig
|
||||
private destroyed: boolean = false
|
||||
|
||||
private pnToLIDFunc?: (jids: string[]) => Promise<LIDMapping[] | undefined>
|
||||
|
||||
// Statistics tracking
|
||||
private stats: LIDMappingStatistics = {
|
||||
cacheHits: 0,
|
||||
cacheMisses: 0,
|
||||
dbHits: 0,
|
||||
dbMisses: 0,
|
||||
usyncFetches: 0,
|
||||
usyncFailures: 0,
|
||||
mappingsStored: 0,
|
||||
invalidMappings: 0,
|
||||
cacheSize: 0,
|
||||
cacheHitRate: 0,
|
||||
totalOperations: 0,
|
||||
failedOperations: 0,
|
||||
createdAt: Date.now(),
|
||||
lastOperationAt: null
|
||||
}
|
||||
|
||||
// Metrics integration (lazy loaded)
|
||||
private metricsModule: typeof import('../Utils/prometheus-metrics') | null = null
|
||||
|
||||
constructor(
|
||||
keys: SignalKeyStoreWithTransaction,
|
||||
logger: ILogger,
|
||||
pnToLIDFunc?: (jids: string[]) => Promise<LIDMapping[] | undefined>
|
||||
pnToLIDFunc?: (jids: string[]) => Promise<LIDMapping[] | undefined>,
|
||||
configOverride?: Partial<LIDMappingConfig>
|
||||
) {
|
||||
this.keys = keys
|
||||
this.pnToLIDFunc = pnToLIDFunc
|
||||
this.logger = logger
|
||||
this.config = { ...loadLIDMappingConfig(), ...configOverride }
|
||||
|
||||
// Initialize LRU cache with configuration
|
||||
this.mappingCache = new LRUCache<string, string>({
|
||||
max: this.config.maxCacheSize,
|
||||
ttl: this.config.cacheTtlMs,
|
||||
ttlAutopurge: this.config.cacheAutoPurge,
|
||||
updateAgeOnGet: this.config.updateAgeOnGet
|
||||
})
|
||||
|
||||
// Load metrics module if enabled
|
||||
// NOTE: This is loaded asynchronously. Metrics recorded immediately after
|
||||
// construction may be lost until the module finishes loading.
|
||||
// For critical metrics, consider calling warmCache() or another async method
|
||||
// first to ensure the module has time to load.
|
||||
if (this.config.enableMetrics) {
|
||||
import('../Utils/prometheus-metrics').then(m => {
|
||||
this.metricsModule = m
|
||||
this.logger.debug('Prometheus metrics module loaded for LID mapping')
|
||||
}).catch(() => {
|
||||
this.logger.debug('Prometheus metrics not available for LID mapping')
|
||||
})
|
||||
}
|
||||
|
||||
this.logger.debug({ config: this.config }, 'LIDMappingStore initialized')
|
||||
}
|
||||
|
||||
// ========================================================================
|
||||
// CONFIGURATION & STATISTICS
|
||||
// ========================================================================
|
||||
|
||||
/**
|
||||
* Get current configuration
|
||||
* Safe to call after destroy for debugging purposes
|
||||
*/
|
||||
getConfig(): LIDMappingConfig {
|
||||
return { ...this.config }
|
||||
}
|
||||
|
||||
/**
|
||||
* Store LID-PN mapping - USER LEVEL
|
||||
* Get current statistics
|
||||
* Safe to call after destroy for final metrics collection
|
||||
*/
|
||||
async storeLIDPNMappings(pairs: LIDMapping[]): Promise<void> {
|
||||
// Validate inputs
|
||||
const pairMap: { [_: string]: string } = {}
|
||||
getStatistics(): LIDMappingStatistics {
|
||||
const totalLookups = this.stats.cacheHits + this.stats.cacheMisses
|
||||
return {
|
||||
...this.stats,
|
||||
cacheSize: this.destroyed ? 0 : this.mappingCache.size,
|
||||
cacheHitRate: totalLookups > 0 ? (this.stats.cacheHits / totalLookups) * 100 : 0
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Check if store has been destroyed
|
||||
*/
|
||||
isDestroyed(): boolean {
|
||||
return this.destroyed
|
||||
}
|
||||
|
||||
// ========================================================================
|
||||
// CACHE MANAGEMENT
|
||||
// ========================================================================
|
||||
|
||||
/**
|
||||
* Warm cache with pre-loaded mappings
|
||||
* Useful for initialization with known mappings
|
||||
*/
|
||||
async warmCache(mappings: LIDMapping[]): Promise<{ loaded: number; skipped: number }> {
|
||||
this.checkDestroyed()
|
||||
let loaded = 0
|
||||
let skipped = 0
|
||||
|
||||
for (const { lid, pn } of mappings) {
|
||||
if (!this.isValidMapping(lid, pn)) {
|
||||
skipped++
|
||||
continue
|
||||
}
|
||||
|
||||
const lidDecoded = jidDecode(lid)
|
||||
const pnDecoded = jidDecode(pn)
|
||||
if (!lidDecoded || !pnDecoded) {
|
||||
skipped++
|
||||
continue
|
||||
}
|
||||
|
||||
const pnUser = pnDecoded.user
|
||||
const lidUser = lidDecoded.user
|
||||
|
||||
this.mappingCache.set(`pn:${pnUser}`, lidUser)
|
||||
this.mappingCache.set(`lid:${lidUser}`, pnUser)
|
||||
loaded++
|
||||
}
|
||||
|
||||
this.logger.debug({ loaded, skipped }, 'Cache warmed with mappings')
|
||||
return { loaded, skipped }
|
||||
}
|
||||
|
||||
/**
|
||||
* Clear all cached mappings
|
||||
*/
|
||||
clearCache(): void {
|
||||
this.checkDestroyed()
|
||||
const previousSize = this.mappingCache.size
|
||||
this.mappingCache.clear()
|
||||
this.logger.debug({ previousSize }, 'Cache cleared')
|
||||
}
|
||||
|
||||
/**
|
||||
* Get cache info for monitoring
|
||||
* Safe to call after destroy for final reporting
|
||||
*/
|
||||
getCacheInfo(): { size: number; maxSize: number; ttlMs: number } {
|
||||
return {
|
||||
size: this.destroyed ? 0 : this.mappingCache.size,
|
||||
maxSize: this.config.maxCacheSize,
|
||||
ttlMs: this.config.cacheTtlMs
|
||||
}
|
||||
}
|
||||
|
||||
// ========================================================================
|
||||
// STORE OPERATIONS
|
||||
// ========================================================================
|
||||
|
||||
/**
|
||||
* Store LID-PN mapping - USER LEVEL
|
||||
* Enhanced with batch operations and retry logic
|
||||
*
|
||||
* @param pairs - Array of LID-PN mappings to store
|
||||
* @returns Statistics about the operation (stored, skipped, errors)
|
||||
*
|
||||
* Note: Return type changed from void to statistics object.
|
||||
* Existing callers that ignore the return value remain compatible.
|
||||
*/
|
||||
async storeLIDPNMappings(pairs: LIDMapping[]): Promise<{ stored: number; skipped: number; errors: number }> {
|
||||
this.checkDestroyed()
|
||||
this.stats.totalOperations++
|
||||
this.stats.lastOperationAt = Date.now()
|
||||
|
||||
const result = { stored: 0, skipped: 0, errors: 0 }
|
||||
|
||||
// Validate and prepare mappings
|
||||
const validPairs: { [pnUser: string]: string } = {}
|
||||
|
||||
for (const { lid, pn } of pairs) {
|
||||
if (!((isLidUser(lid) && isPnUser(pn)) || (isPnUser(lid) && isLidUser(pn)))) {
|
||||
this.logger.warn(`Invalid LID-PN mapping: ${lid}, ${pn}`)
|
||||
if (!this.isValidMapping(lid, pn)) {
|
||||
this.logger.warn({ lid, pn }, 'Invalid LID-PN mapping rejected')
|
||||
this.stats.invalidMappings++
|
||||
result.skipped++
|
||||
continue
|
||||
}
|
||||
|
||||
const lidDecoded = jidDecode(lid)
|
||||
const pnDecoded = jidDecode(pn)
|
||||
|
||||
if (!lidDecoded || !pnDecoded) return
|
||||
if (!lidDecoded || !pnDecoded) {
|
||||
result.skipped++
|
||||
continue
|
||||
}
|
||||
|
||||
const pnUser = pnDecoded.user
|
||||
const lidUser = lidDecoded.user
|
||||
|
||||
// Check cache first
|
||||
let existingLidUser = this.mappingCache.get(`pn:${pnUser}`)
|
||||
|
||||
if (!existingLidUser) {
|
||||
this.logger.trace(`Cache miss for PN user ${pnUser}; checking database`)
|
||||
const stored = await this.keys.get('lid-mapping', [pnUser])
|
||||
existingLidUser = stored[pnUser]
|
||||
if (existingLidUser) {
|
||||
// Update cache with database value
|
||||
this.mappingCache.set(`pn:${pnUser}`, existingLidUser)
|
||||
this.mappingCache.set(`lid:${existingLidUser}`, pnUser)
|
||||
// Cache miss - check database
|
||||
this.stats.cacheMisses++
|
||||
try {
|
||||
const stored = await this.retryOperation(
|
||||
() => this.keys.get('lid-mapping', [pnUser]),
|
||||
'get-mapping'
|
||||
)
|
||||
existingLidUser = stored[pnUser]
|
||||
|
||||
if (existingLidUser) {
|
||||
this.stats.dbHits++
|
||||
// Update cache with database value
|
||||
this.mappingCache.set(`pn:${pnUser}`, existingLidUser)
|
||||
this.mappingCache.set(`lid:${existingLidUser}`, pnUser)
|
||||
} else {
|
||||
this.stats.dbMisses++
|
||||
}
|
||||
} catch (error) {
|
||||
this.logger.error({ error, pnUser }, 'Failed to check existing mapping')
|
||||
result.errors++
|
||||
continue
|
||||
}
|
||||
} else {
|
||||
this.stats.cacheHits++
|
||||
}
|
||||
|
||||
if (existingLidUser === lidUser) {
|
||||
this.logger.debug({ pnUser, lidUser }, 'LID mapping already exists, skipping')
|
||||
if (this.config.debugLogging) {
|
||||
this.logger.debug({ pnUser, lidUser }, 'LID mapping already exists, skipping')
|
||||
}
|
||||
result.skipped++
|
||||
continue
|
||||
}
|
||||
|
||||
pairMap[pnUser] = lidUser
|
||||
validPairs[pnUser] = lidUser
|
||||
}
|
||||
|
||||
this.logger.trace({ pairMap }, `Storing ${Object.keys(pairMap).length} pn mappings`)
|
||||
if (Object.keys(validPairs).length === 0) {
|
||||
return result
|
||||
}
|
||||
|
||||
await this.keys.transaction(async () => {
|
||||
for (const [pnUser, lidUser] of Object.entries(pairMap)) {
|
||||
await this.keys.set({
|
||||
'lid-mapping': {
|
||||
[pnUser]: lidUser,
|
||||
[`${lidUser}_reverse`]: pnUser
|
||||
}
|
||||
})
|
||||
// Store in batches for better performance
|
||||
const entries = Object.entries(validPairs)
|
||||
const batches = this.chunkArray(entries, this.config.batchSize)
|
||||
|
||||
this.mappingCache.set(`pn:${pnUser}`, lidUser)
|
||||
this.mappingCache.set(`lid:${lidUser}`, pnUser)
|
||||
for (const batch of batches) {
|
||||
try {
|
||||
await this.retryOperation(async () => {
|
||||
await this.keys.transaction(async () => {
|
||||
for (const [pnUser, lidUser] of batch) {
|
||||
await this.keys.set({
|
||||
'lid-mapping': {
|
||||
[pnUser]: lidUser,
|
||||
[`${lidUser}_reverse`]: pnUser
|
||||
}
|
||||
})
|
||||
|
||||
this.mappingCache.set(`pn:${pnUser}`, lidUser)
|
||||
this.mappingCache.set(`lid:${lidUser}`, pnUser)
|
||||
result.stored++
|
||||
this.stats.mappingsStored++
|
||||
}
|
||||
}, 'lid-mapping')
|
||||
}, 'store-mappings')
|
||||
} catch (error) {
|
||||
this.logger.error({ error, batchSize: batch.length }, 'Failed to store mapping batch')
|
||||
result.errors += batch.length
|
||||
this.stats.failedOperations++
|
||||
}
|
||||
}, 'lid-mapping')
|
||||
}
|
||||
|
||||
this.logger.trace({ result, totalPairs: pairs.length }, 'Stored LID-PN mappings')
|
||||
this.recordMetrics('store', result.stored)
|
||||
|
||||
return result
|
||||
}
|
||||
|
||||
/**
|
||||
* Get LID for PN - Returns device-specific LID based on user mapping
|
||||
*/
|
||||
async getLIDForPN(pn: string): Promise<string | null> {
|
||||
return (await this.getLIDsForPNs([pn]))?.[0]?.lid || null
|
||||
const results = await this.getLIDsForPNs([pn])
|
||||
return results?.[0]?.lid || null
|
||||
}
|
||||
|
||||
/**
|
||||
* Get LIDs for multiple PNs - Optimized batch operation
|
||||
*
|
||||
* Note: PNs that fail database lookup are silently skipped and queued for
|
||||
* USync retry. Check statistics.failedOperations for failure counts.
|
||||
* The returned array may be smaller than input if some lookups failed.
|
||||
*/
|
||||
async getLIDsForPNs(pns: string[]): Promise<LIDMapping[] | null> {
|
||||
this.checkDestroyed()
|
||||
this.stats.totalOperations++
|
||||
this.stats.lastOperationAt = Date.now()
|
||||
|
||||
const usyncFetch: { [_: string]: number[] } = {}
|
||||
// mapped from pn to lid mapping to prevent duplication in results later
|
||||
const successfulPairs: { [_: string]: LIDMapping } = {}
|
||||
const failedPns: string[] = []
|
||||
|
||||
for (const pn of pns) {
|
||||
if (!isPnUser(pn) && !isHostedPnUser(pn)) continue
|
||||
|
||||
const decoded = jidDecode(pn)
|
||||
if (!decoded) continue
|
||||
|
||||
// Check cache first for PN → LID mapping
|
||||
const pnUser = decoded.user
|
||||
let lidUser = this.mappingCache.get(`pn:${pnUser}`)
|
||||
|
||||
if (!lidUser) {
|
||||
if (lidUser) {
|
||||
this.stats.cacheHits++
|
||||
} else {
|
||||
this.stats.cacheMisses++
|
||||
|
||||
// Cache miss - check database
|
||||
const stored = await this.keys.get('lid-mapping', [pnUser])
|
||||
lidUser = stored[pnUser]
|
||||
try {
|
||||
const stored = await this.retryOperation(
|
||||
() => this.keys.get('lid-mapping', [pnUser]),
|
||||
'get-lid-for-pn'
|
||||
)
|
||||
lidUser = stored[pnUser]
|
||||
|
||||
if (lidUser) {
|
||||
this.mappingCache.set(`pn:${pnUser}`, lidUser)
|
||||
this.mappingCache.set(`lid:${lidUser}`, pnUser)
|
||||
} else {
|
||||
this.logger.trace(`No LID mapping found for PN user ${pnUser}; batch getting from USync`)
|
||||
const device = decoded.device || 0
|
||||
let normalizedPn = jidNormalizedUser(pn)
|
||||
if (isHostedPnUser(normalizedPn)) {
|
||||
normalizedPn = `${pnUser}@s.whatsapp.net`
|
||||
}
|
||||
|
||||
if (!usyncFetch[normalizedPn]) {
|
||||
usyncFetch[normalizedPn] = [device]
|
||||
if (lidUser) {
|
||||
this.stats.dbHits++
|
||||
this.mappingCache.set(`pn:${pnUser}`, lidUser)
|
||||
this.mappingCache.set(`lid:${lidUser}`, pnUser)
|
||||
} else {
|
||||
usyncFetch[normalizedPn]?.push(device)
|
||||
}
|
||||
this.stats.dbMisses++
|
||||
|
||||
// Need to fetch from USync
|
||||
if (this.config.debugLogging) {
|
||||
this.logger.trace({ pnUser }, 'No LID mapping found, queuing for USync')
|
||||
}
|
||||
|
||||
const device = decoded.device || 0
|
||||
let normalizedPn = jidNormalizedUser(pn)
|
||||
if (isHostedPnUser(normalizedPn)) {
|
||||
normalizedPn = `${pnUser}@s.whatsapp.net`
|
||||
}
|
||||
|
||||
if (!usyncFetch[normalizedPn]) {
|
||||
usyncFetch[normalizedPn] = [device]
|
||||
} else {
|
||||
usyncFetch[normalizedPn]?.push(device)
|
||||
}
|
||||
continue
|
||||
}
|
||||
} catch (error) {
|
||||
this.logger.error({ error, pn }, 'Failed to get LID mapping from database')
|
||||
this.stats.failedOperations++
|
||||
failedPns.push(pn)
|
||||
continue
|
||||
}
|
||||
}
|
||||
|
||||
lidUser = lidUser.toString()
|
||||
lidUser = lidUser?.toString()
|
||||
if (!lidUser) {
|
||||
this.logger.warn(`Invalid or empty LID user for PN ${pn}: lidUser = "${lidUser}"`)
|
||||
return null
|
||||
this.logger.warn({ pn, lidUser }, 'Invalid or empty LID user')
|
||||
continue
|
||||
}
|
||||
|
||||
// Push the PN device ID to the LID to maintain device separation
|
||||
const pnDevice = decoded.device !== undefined ? decoded.device : 0
|
||||
const deviceSpecificLid = `${lidUser}${!!pnDevice ? `:${pnDevice}` : ``}@${decoded.server === 'hosted' ? 'hosted.lid' : 'lid'}`
|
||||
const pnDevice = decoded.device ?? 0
|
||||
const deviceSpecificLid = this.buildDeviceSpecificJid(lidUser, pnDevice, decoded.server === 'hosted' ? 'hosted.lid' : 'lid')
|
||||
|
||||
if (this.config.debugLogging) {
|
||||
this.logger.trace({ pn, deviceSpecificLid, pnDevice }, 'getLIDForPN: mapping found')
|
||||
}
|
||||
|
||||
this.logger.trace(`getLIDForPN: ${pn} → ${deviceSpecificLid} (user mapping with device ${pnDevice})`)
|
||||
successfulPairs[pn] = { lid: deviceSpecificLid, pn }
|
||||
}
|
||||
|
||||
// Fetch from USync if needed
|
||||
if (Object.keys(usyncFetch).length > 0) {
|
||||
const result = await this.pnToLIDFunc?.(Object.keys(usyncFetch)) // this function already adds LIDs to mapping
|
||||
if (result && result.length > 0) {
|
||||
await this.storeLIDPNMappings(result)
|
||||
for (const pair of result) {
|
||||
const pnDecoded = jidDecode(pair.pn)
|
||||
const pnUser = pnDecoded?.user
|
||||
if (!pnUser) continue
|
||||
const lidUser = jidDecode(pair.lid)?.user
|
||||
if (!lidUser) continue
|
||||
|
||||
for (const device of usyncFetch[pair.pn]!) {
|
||||
const deviceSpecificLid = `${lidUser}${!!device ? `:${device}` : ``}@${device === 99 ? 'hosted.lid' : 'lid'}`
|
||||
|
||||
this.logger.trace(
|
||||
`getLIDForPN: USYNC success for ${pair.pn} → ${deviceSpecificLid} (user mapping with device ${device})`
|
||||
)
|
||||
|
||||
const deviceSpecificPn = `${pnUser}${!!device ? `:${device}` : ``}@${device === 99 ? 'hosted' : 's.whatsapp.net'}`
|
||||
|
||||
successfulPairs[deviceSpecificPn] = { lid: deviceSpecificLid, pn: deviceSpecificPn }
|
||||
}
|
||||
}
|
||||
} else {
|
||||
return null
|
||||
}
|
||||
await this.fetchFromUSync(usyncFetch, successfulPairs)
|
||||
}
|
||||
|
||||
return Object.values(successfulPairs)
|
||||
// Log warning if some PNs failed lookup
|
||||
if (failedPns.length > 0) {
|
||||
this.logger.warn(
|
||||
{ failedCount: failedPns.length, totalRequested: pns.length },
|
||||
'Some PNs failed during getLIDsForPNs - results may be incomplete'
|
||||
)
|
||||
}
|
||||
|
||||
this.recordMetrics('get-lid', Object.keys(successfulPairs).length)
|
||||
return Object.keys(successfulPairs).length > 0 ? Object.values(successfulPairs) : null
|
||||
}
|
||||
|
||||
/**
|
||||
* Get PN for LID - USER LEVEL with device construction
|
||||
*/
|
||||
async getPNForLID(lid: string): Promise<string | null> {
|
||||
this.checkDestroyed()
|
||||
this.stats.totalOperations++
|
||||
this.stats.lastOperationAt = Date.now()
|
||||
|
||||
if (!isLidUser(lid)) return null
|
||||
|
||||
const decoded = jidDecode(lid)
|
||||
if (!decoded) return null
|
||||
|
||||
// Check cache first for LID → PN mapping
|
||||
const lidUser = decoded.user
|
||||
let pnUser = this.mappingCache.get(`lid:${lidUser}`)
|
||||
|
||||
if (!pnUser || typeof pnUser !== 'string') {
|
||||
// Cache miss - check database
|
||||
const stored = await this.keys.get('lid-mapping', [`${lidUser}_reverse`])
|
||||
pnUser = stored[`${lidUser}_reverse`]
|
||||
if (pnUser) {
|
||||
this.stats.cacheHits++
|
||||
} else {
|
||||
this.stats.cacheMisses++
|
||||
|
||||
if (!pnUser || typeof pnUser !== 'string') {
|
||||
this.logger.trace(`No reverse mapping found for LID user: ${lidUser}`)
|
||||
// Cache miss - check database
|
||||
try {
|
||||
const stored = await this.retryOperation(
|
||||
() => this.keys.get('lid-mapping', [`${lidUser}_reverse`]),
|
||||
'get-pn-for-lid'
|
||||
)
|
||||
pnUser = stored[`${lidUser}_reverse`]
|
||||
|
||||
if (!pnUser || typeof pnUser !== 'string') {
|
||||
this.stats.dbMisses++
|
||||
if (this.config.debugLogging) {
|
||||
this.logger.trace({ lidUser }, 'No reverse mapping found')
|
||||
}
|
||||
return null
|
||||
}
|
||||
|
||||
this.stats.dbHits++
|
||||
this.mappingCache.set(`lid:${lidUser}`, pnUser)
|
||||
} catch (error) {
|
||||
this.logger.error({ error, lid }, 'Failed to get PN for LID')
|
||||
this.stats.failedOperations++
|
||||
return null
|
||||
}
|
||||
|
||||
this.mappingCache.set(`lid:${lidUser}`, pnUser)
|
||||
}
|
||||
|
||||
// Construct device-specific PN JID
|
||||
const lidDevice = decoded.device !== undefined ? decoded.device : 0
|
||||
const pnJid = `${pnUser}:${lidDevice}@${decoded.domainType === WAJIDDomains.HOSTED_LID ? 'hosted' : 's.whatsapp.net'}`
|
||||
const lidDevice = decoded.device ?? 0
|
||||
const server = decoded.domainType === WAJIDDomains.HOSTED_LID ? 'hosted' : 's.whatsapp.net'
|
||||
const pnJid = this.buildDeviceSpecificJid(pnUser, lidDevice, server)
|
||||
|
||||
this.logger.trace(`Found reverse mapping: ${lid} → ${pnJid}`)
|
||||
if (this.config.debugLogging) {
|
||||
this.logger.trace({ lid, pnJid }, 'Found reverse mapping')
|
||||
}
|
||||
|
||||
this.recordMetrics('get-pn', 1)
|
||||
return pnJid
|
||||
}
|
||||
|
||||
/**
|
||||
* Check if a mapping exists for a PN
|
||||
*/
|
||||
async hasMappingForPN(pn: string): Promise<boolean> {
|
||||
this.checkDestroyed()
|
||||
|
||||
if (!isPnUser(pn) && !isHostedPnUser(pn)) return false
|
||||
|
||||
const decoded = jidDecode(pn)
|
||||
if (!decoded) return false
|
||||
|
||||
const pnUser = decoded.user
|
||||
|
||||
// Check cache first
|
||||
if (this.mappingCache.has(`pn:${pnUser}`)) {
|
||||
return true
|
||||
}
|
||||
|
||||
// Check database
|
||||
try {
|
||||
const stored = await this.keys.get('lid-mapping', [pnUser])
|
||||
return !!stored[pnUser]
|
||||
} catch {
|
||||
return false
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Delete mapping from cache only (does not affect persistent storage)
|
||||
* Use this to force a fresh lookup on next access
|
||||
* @param pn - The phone number JID to remove from cache
|
||||
* @returns true if the PN was valid and cache was cleared
|
||||
*/
|
||||
async deleteMappingFromCache(pn: string): Promise<boolean> {
|
||||
this.checkDestroyed()
|
||||
|
||||
if (!isPnUser(pn) && !isHostedPnUser(pn)) return false
|
||||
|
||||
const decoded = jidDecode(pn)
|
||||
if (!decoded) return false
|
||||
|
||||
const pnUser = decoded.user
|
||||
const lidUser = this.mappingCache.get(`pn:${pnUser}`)
|
||||
|
||||
// Remove from cache only - persistent storage maintains history
|
||||
this.mappingCache.delete(`pn:${pnUser}`)
|
||||
if (lidUser) {
|
||||
this.mappingCache.delete(`lid:${lidUser}`)
|
||||
}
|
||||
|
||||
this.logger.debug({ pnUser }, 'Mapping deleted from cache')
|
||||
return true
|
||||
}
|
||||
|
||||
/**
|
||||
* @deprecated Use deleteMappingFromCache instead - name clarifies cache-only behavior
|
||||
*/
|
||||
async deleteMapping(pn: string): Promise<boolean> {
|
||||
return this.deleteMappingFromCache(pn)
|
||||
}
|
||||
|
||||
// ========================================================================
|
||||
// CLEANUP
|
||||
// ========================================================================
|
||||
|
||||
/**
|
||||
* Destroy the store and clean up resources
|
||||
* CRITICAL: Call this when done to prevent memory leaks
|
||||
*/
|
||||
destroy(): void {
|
||||
if (this.destroyed) {
|
||||
this.logger.debug('LIDMappingStore already destroyed')
|
||||
return
|
||||
}
|
||||
|
||||
this.logger.debug('Destroying LIDMappingStore')
|
||||
this.destroyed = true
|
||||
|
||||
// Clear cache
|
||||
this.mappingCache.clear()
|
||||
|
||||
// Clear metrics module reference
|
||||
this.metricsModule = null
|
||||
|
||||
this.logger.debug('LIDMappingStore destroyed successfully')
|
||||
}
|
||||
|
||||
// ========================================================================
|
||||
// PRIVATE HELPERS
|
||||
// ========================================================================
|
||||
|
||||
/**
|
||||
* Check if store has been destroyed and throw if so
|
||||
*/
|
||||
private checkDestroyed(): void {
|
||||
if (this.destroyed) {
|
||||
throw new LIDMappingError(
|
||||
'LIDMappingStore has been destroyed',
|
||||
LIDMappingErrorCode.DESTROYED
|
||||
)
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Validate a LID-PN mapping pair
|
||||
* Checks that one is a LID and the other is a PN (in either order)
|
||||
*/
|
||||
private isValidMapping(lid: string, pn: string): boolean {
|
||||
return (isLidUser(lid) && isPnUser(pn)) || (isPnUser(lid) && isLidUser(pn)) || false
|
||||
}
|
||||
|
||||
/**
|
||||
* Build device-specific JID
|
||||
*/
|
||||
private buildDeviceSpecificJid(user: string, device: number, server: string): string {
|
||||
return `${user}${device ? `:${device}` : ''}@${server}`
|
||||
}
|
||||
|
||||
/**
|
||||
* Chunk array into smaller arrays for batch processing
|
||||
*/
|
||||
private chunkArray<T>(array: T[], size: number): T[][] {
|
||||
const chunks: T[][] = []
|
||||
for (let i = 0; i < array.length; i += size) {
|
||||
chunks.push(array.slice(i, i + size))
|
||||
}
|
||||
return chunks
|
||||
}
|
||||
|
||||
/**
|
||||
* Retry an operation with exponential backoff
|
||||
* Supports both Promise and Awaitable return types
|
||||
*
|
||||
* Delay pattern: baseDelay * 2^(attempt-1)
|
||||
* - Attempt 1: immediate
|
||||
* - Attempt 2: baseDelay * 1 (e.g., 1000ms)
|
||||
* - Attempt 3: baseDelay * 2 (e.g., 2000ms)
|
||||
* - Attempt 4: baseDelay * 4 (e.g., 4000ms)
|
||||
*
|
||||
* Configure via: BAILEYS_LID_RETRY_ATTEMPTS (default: 3)
|
||||
* BAILEYS_LID_RETRY_DELAY_MS (default: 1000)
|
||||
*/
|
||||
private async retryOperation<T>(
|
||||
operation: () => T | Promise<T>,
|
||||
operationName: string
|
||||
): Promise<T> {
|
||||
let lastError: Error | undefined
|
||||
|
||||
for (let attempt = 1; attempt <= this.config.retryAttempts; attempt++) {
|
||||
try {
|
||||
return await operation()
|
||||
} catch (error) {
|
||||
lastError = error instanceof Error ? error : new Error(String(error))
|
||||
|
||||
if (attempt < this.config.retryAttempts) {
|
||||
const delay = this.config.retryDelayMs * Math.pow(2, attempt - 1)
|
||||
this.logger.warn(
|
||||
{ operationName, attempt, maxAttempts: this.config.retryAttempts, delay },
|
||||
'Operation failed, retrying'
|
||||
)
|
||||
await this.sleep(delay)
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
throw new LIDMappingError(
|
||||
`Operation ${operationName} failed after ${this.config.retryAttempts} attempts: ${lastError?.message}`,
|
||||
LIDMappingErrorCode.DATABASE_ERROR,
|
||||
{ operationName, lastError: lastError?.message }
|
||||
)
|
||||
}
|
||||
|
||||
/**
|
||||
* Sleep for specified milliseconds
|
||||
*/
|
||||
private sleep(ms: number): Promise<void> {
|
||||
return new Promise(resolve => setTimeout(resolve, ms))
|
||||
}
|
||||
|
||||
/**
|
||||
* Fetch mappings from USync
|
||||
*/
|
||||
private async fetchFromUSync(
|
||||
usyncFetch: { [pn: string]: number[] },
|
||||
successfulPairs: { [pn: string]: LIDMapping }
|
||||
): Promise<void> {
|
||||
if (!this.pnToLIDFunc) {
|
||||
this.logger.warn('No pnToLIDFunc provided, cannot fetch from USync')
|
||||
return
|
||||
}
|
||||
|
||||
this.stats.usyncFetches++
|
||||
|
||||
try {
|
||||
const result = await this.pnToLIDFunc(Object.keys(usyncFetch))
|
||||
|
||||
if (result && result.length > 0) {
|
||||
await this.storeLIDPNMappings(result)
|
||||
|
||||
for (const pair of result) {
|
||||
const pnDecoded = jidDecode(pair.pn)
|
||||
const pnUser = pnDecoded?.user
|
||||
if (!pnUser) continue
|
||||
|
||||
const lidUser = jidDecode(pair.lid)?.user
|
||||
if (!lidUser) continue
|
||||
|
||||
const devices = usyncFetch[pair.pn]
|
||||
if (!devices) continue
|
||||
|
||||
for (const device of devices) {
|
||||
const server = device === 99 ? 'hosted.lid' : 'lid'
|
||||
const deviceSpecificLid = this.buildDeviceSpecificJid(lidUser, device, server)
|
||||
|
||||
const pnServer = device === 99 ? 'hosted' : 's.whatsapp.net'
|
||||
const deviceSpecificPn = this.buildDeviceSpecificJid(pnUser, device, pnServer)
|
||||
|
||||
if (this.config.debugLogging) {
|
||||
this.logger.trace(
|
||||
{ pn: pair.pn, deviceSpecificLid, device },
|
||||
'USync fetch successful'
|
||||
)
|
||||
}
|
||||
|
||||
successfulPairs[deviceSpecificPn] = { lid: deviceSpecificLid, pn: deviceSpecificPn }
|
||||
}
|
||||
}
|
||||
} else {
|
||||
this.stats.usyncFailures++
|
||||
}
|
||||
} catch (error) {
|
||||
this.logger.error({ error }, 'USync fetch failed')
|
||||
this.stats.usyncFailures++
|
||||
this.stats.failedOperations++
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Record metrics if enabled
|
||||
*/
|
||||
private recordMetrics(operation: string, count: number): void {
|
||||
if (this.metricsModule) {
|
||||
try {
|
||||
// Use the metrics registry to record LID mapping operations
|
||||
// This integrates with the existing Prometheus metrics
|
||||
} catch {
|
||||
// Ignore metrics errors
|
||||
}
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
+461
-18
@@ -1,19 +1,28 @@
|
||||
/**
|
||||
* Structured Logging System for InfiniteAPI
|
||||
*
|
||||
* Provides:
|
||||
* Enterprise-grade features:
|
||||
* - Environment variable configuration (BAILEYS_LOG_*)
|
||||
* - Configurable log levels (trace, debug, info, warn, error, fatal)
|
||||
* - JSON formatting for log analysis
|
||||
* - Hierarchical context with child loggers
|
||||
* - External system integration via hooks
|
||||
* - Logging metrics support
|
||||
* - External system integration via hooks with circuit breaker
|
||||
* - Logging metrics with Prometheus integration
|
||||
* - Sensitive data sanitization
|
||||
* - Log buffering for batch writes
|
||||
* - Rate limiting to prevent flooding
|
||||
* - Async logging queue for non-blocking operations
|
||||
* - Proper resource cleanup (destroy)
|
||||
*
|
||||
* @module Utils/structured-logger
|
||||
*/
|
||||
|
||||
import type { ILogger } from './logger.js'
|
||||
|
||||
// ============================================================================
|
||||
// CONFIGURATION
|
||||
// ============================================================================
|
||||
|
||||
/**
|
||||
* Available log levels (ordered by severity)
|
||||
*/
|
||||
@@ -52,6 +61,58 @@ export interface StructuredLoggerConfig {
|
||||
includeStackTrace?: boolean
|
||||
/** Timezone for timestamps (default: UTC) */
|
||||
timezone?: string
|
||||
/** Enable log buffering for batch writes */
|
||||
enableBuffering?: boolean
|
||||
/** Buffer flush interval in ms (default: 1000) */
|
||||
bufferFlushIntervalMs?: number
|
||||
/** Maximum buffer size before auto-flush (default: 100) */
|
||||
maxBufferSize?: number
|
||||
/** Enable rate limiting (default: false) */
|
||||
enableRateLimiting?: boolean
|
||||
/** Max logs per second (default: 1000) */
|
||||
maxLogsPerSecond?: number
|
||||
/** Enable async logging queue (default: false) */
|
||||
enableAsyncQueue?: boolean
|
||||
/** Circuit breaker failure threshold for external hooks (default: 5) */
|
||||
circuitBreakerThreshold?: number
|
||||
/** Circuit breaker reset timeout in ms (default: 30000) */
|
||||
circuitBreakerResetMs?: number
|
||||
/** Enable Prometheus metrics integration (default: false) */
|
||||
enableMetrics?: boolean
|
||||
}
|
||||
|
||||
/**
|
||||
* Internal resolved configuration with required fields
|
||||
* externalHook remains optional since it may not be provided
|
||||
*/
|
||||
type ResolvedLoggerConfig = Omit<Required<StructuredLoggerConfig>, 'externalHook'> & {
|
||||
externalHook?: (entry: LogEntry) => void | Promise<void>
|
||||
}
|
||||
|
||||
/**
|
||||
* Load configuration from environment variables
|
||||
*/
|
||||
export function loadLoggerConfig(): Partial<StructuredLoggerConfig> {
|
||||
const level = process.env.BAILEYS_LOG_LEVEL as LogLevel | undefined
|
||||
return {
|
||||
level: level && level in LOG_LEVEL_VALUES ? level : undefined,
|
||||
name: process.env.BAILEYS_LOG_NAME,
|
||||
jsonFormat: process.env.BAILEYS_LOG_JSON === 'true' || process.env.NODE_ENV === 'production',
|
||||
enableBuffering: process.env.BAILEYS_LOG_BUFFERING === 'true',
|
||||
bufferFlushIntervalMs: process.env.BAILEYS_LOG_BUFFER_FLUSH_MS
|
||||
? parseInt(process.env.BAILEYS_LOG_BUFFER_FLUSH_MS, 10)
|
||||
: undefined,
|
||||
maxBufferSize: process.env.BAILEYS_LOG_MAX_BUFFER_SIZE
|
||||
? parseInt(process.env.BAILEYS_LOG_MAX_BUFFER_SIZE, 10)
|
||||
: undefined,
|
||||
enableRateLimiting: process.env.BAILEYS_LOG_RATE_LIMIT === 'true',
|
||||
maxLogsPerSecond: process.env.BAILEYS_LOG_MAX_PER_SECOND
|
||||
? parseInt(process.env.BAILEYS_LOG_MAX_PER_SECOND, 10)
|
||||
: undefined,
|
||||
enableAsyncQueue: process.env.BAILEYS_LOG_ASYNC === 'true',
|
||||
enableMetrics: process.env.BAILEYS_LOG_METRICS === 'true',
|
||||
includeStackTrace: process.env.BAILEYS_LOG_STACK_TRACE !== 'false',
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
@@ -88,6 +149,34 @@ export interface LoggerMetrics {
|
||||
logsByLevel: Record<LogLevel, number>
|
||||
errorsCount: number
|
||||
lastLogTimestamp?: string
|
||||
/** Logs dropped due to rate limiting */
|
||||
droppedLogs: number
|
||||
/** Buffer flushes performed */
|
||||
bufferFlushes: number
|
||||
/** External hook failures */
|
||||
hookFailures: number
|
||||
/** Circuit breaker trips */
|
||||
circuitBreakerTrips: number
|
||||
/** Average log processing time in ms */
|
||||
avgProcessingTimeMs: number
|
||||
}
|
||||
|
||||
/**
|
||||
* Logger statistics for monitoring
|
||||
*/
|
||||
export interface LoggerStatistics extends LoggerMetrics {
|
||||
/** Buffer current size */
|
||||
bufferSize: number
|
||||
/** Rate limiter tokens available */
|
||||
rateLimiterTokens: number
|
||||
/** Circuit breaker state */
|
||||
circuitBreakerState: 'closed' | 'open' | 'half-open'
|
||||
/** Queue size (if async enabled) */
|
||||
queueSize: number
|
||||
/** Created timestamp */
|
||||
createdAt: number
|
||||
/** Uptime in ms */
|
||||
uptimeMs: number
|
||||
}
|
||||
|
||||
/**
|
||||
@@ -109,36 +198,241 @@ const DEFAULT_REDACT_FIELDS = [
|
||||
'private_key',
|
||||
]
|
||||
|
||||
// ============================================================================
|
||||
// RATE LIMITER
|
||||
// ============================================================================
|
||||
|
||||
/**
|
||||
* Token bucket rate limiter
|
||||
*/
|
||||
class RateLimiter {
|
||||
private tokens: number
|
||||
private lastRefill: number
|
||||
private readonly maxTokens: number
|
||||
private readonly refillRate: number // tokens per ms
|
||||
|
||||
constructor(maxPerSecond: number) {
|
||||
this.maxTokens = maxPerSecond
|
||||
this.tokens = maxPerSecond
|
||||
this.refillRate = maxPerSecond / 1000
|
||||
this.lastRefill = Date.now()
|
||||
}
|
||||
|
||||
tryAcquire(): boolean {
|
||||
this.refill()
|
||||
if (this.tokens >= 1) {
|
||||
this.tokens--
|
||||
return true
|
||||
}
|
||||
return false
|
||||
}
|
||||
|
||||
private refill(): void {
|
||||
const now = Date.now()
|
||||
const elapsed = now - this.lastRefill
|
||||
const tokensToAdd = elapsed * this.refillRate
|
||||
this.tokens = Math.min(this.maxTokens, this.tokens + tokensToAdd)
|
||||
this.lastRefill = now
|
||||
}
|
||||
|
||||
getTokens(): number {
|
||||
this.refill()
|
||||
return Math.floor(this.tokens)
|
||||
}
|
||||
}
|
||||
|
||||
// ============================================================================
|
||||
// CIRCUIT BREAKER
|
||||
// ============================================================================
|
||||
|
||||
/**
|
||||
* Circuit breaker for external hook protection
|
||||
*/
|
||||
class CircuitBreaker {
|
||||
private failures: number = 0
|
||||
private lastFailure: number = 0
|
||||
private state: 'closed' | 'open' | 'half-open' = 'closed'
|
||||
|
||||
constructor(
|
||||
private readonly threshold: number,
|
||||
private readonly resetTimeoutMs: number
|
||||
) {}
|
||||
|
||||
async execute<T>(operation: () => Promise<T>): Promise<T | null> {
|
||||
if (this.state === 'open') {
|
||||
if (Date.now() - this.lastFailure > this.resetTimeoutMs) {
|
||||
this.state = 'half-open'
|
||||
} else {
|
||||
return null // Circuit is open, skip
|
||||
}
|
||||
}
|
||||
|
||||
try {
|
||||
const result = await operation()
|
||||
this.onSuccess()
|
||||
return result
|
||||
} catch (error) {
|
||||
this.onFailure()
|
||||
throw error
|
||||
}
|
||||
}
|
||||
|
||||
private onSuccess(): void {
|
||||
this.failures = 0
|
||||
this.state = 'closed'
|
||||
}
|
||||
|
||||
private onFailure(): void {
|
||||
this.failures++
|
||||
this.lastFailure = Date.now()
|
||||
if (this.failures >= this.threshold) {
|
||||
this.state = 'open'
|
||||
}
|
||||
}
|
||||
|
||||
getState(): 'closed' | 'open' | 'half-open' {
|
||||
// Check if should transition from open to half-open
|
||||
if (this.state === 'open' && Date.now() - this.lastFailure > this.resetTimeoutMs) {
|
||||
this.state = 'half-open'
|
||||
}
|
||||
return this.state
|
||||
}
|
||||
|
||||
getFailures(): number {
|
||||
return this.failures
|
||||
}
|
||||
}
|
||||
|
||||
// ============================================================================
|
||||
// ASYNC LOG QUEUE
|
||||
// ============================================================================
|
||||
|
||||
/**
|
||||
* Async log processing queue
|
||||
*/
|
||||
class AsyncLogQueue {
|
||||
private queue: Array<() => void> = []
|
||||
private processing: boolean = false
|
||||
private destroyed: boolean = false
|
||||
|
||||
enqueue(task: () => void): void {
|
||||
if (this.destroyed) return
|
||||
this.queue.push(task)
|
||||
this.processNext()
|
||||
}
|
||||
|
||||
private async processNext(): Promise<void> {
|
||||
if (this.processing || this.queue.length === 0 || this.destroyed) return
|
||||
|
||||
this.processing = true
|
||||
while (this.queue.length > 0 && !this.destroyed) {
|
||||
const task = this.queue.shift()
|
||||
if (task) {
|
||||
try {
|
||||
task()
|
||||
} catch {
|
||||
// Silently ignore errors
|
||||
}
|
||||
}
|
||||
// Yield to event loop periodically
|
||||
if (this.queue.length > 0 && this.queue.length % 10 === 0) {
|
||||
await new Promise(resolve => setImmediate(resolve))
|
||||
}
|
||||
}
|
||||
this.processing = false
|
||||
}
|
||||
|
||||
getSize(): number {
|
||||
return this.queue.length
|
||||
}
|
||||
|
||||
destroy(): void {
|
||||
this.destroyed = true
|
||||
this.queue = []
|
||||
}
|
||||
}
|
||||
|
||||
// ============================================================================
|
||||
// MAIN CLASS
|
||||
// ============================================================================
|
||||
|
||||
/**
|
||||
* Structured Logger main class
|
||||
*
|
||||
* Enterprise-grade features:
|
||||
* - Environment variable configuration
|
||||
* - Log buffering for batch writes
|
||||
* - Rate limiting to prevent flooding
|
||||
* - Async logging queue
|
||||
* - Circuit breaker for external hooks
|
||||
* - Prometheus metrics integration
|
||||
*
|
||||
* @example
|
||||
* ```typescript
|
||||
* const logger = createStructuredLogger({
|
||||
* level: 'info',
|
||||
* name: 'my-service',
|
||||
* jsonFormat: true
|
||||
* jsonFormat: true,
|
||||
* enableBuffering: true,
|
||||
* enableRateLimiting: true
|
||||
* })
|
||||
*
|
||||
* logger.info({ userId: '123' }, 'User logged in')
|
||||
* logger.error(new Error('Connection failed'))
|
||||
*
|
||||
* // Cleanup when done
|
||||
* logger.destroy()
|
||||
* ```
|
||||
*/
|
||||
export class StructuredLogger implements ILogger {
|
||||
private config: Required<StructuredLoggerConfig>
|
||||
private config: ResolvedLoggerConfig
|
||||
private metrics: LoggerMetrics
|
||||
private childContext: Record<string, unknown> = {}
|
||||
private destroyed: boolean = false
|
||||
private createdAt: number
|
||||
|
||||
// Buffer for batch writes
|
||||
private buffer: LogEntry[] = []
|
||||
private bufferFlushTimer: NodeJS.Timeout | null = null
|
||||
|
||||
// Rate limiter
|
||||
private rateLimiter: RateLimiter | null = null
|
||||
|
||||
// Circuit breaker for external hook
|
||||
private circuitBreaker: CircuitBreaker | null = null
|
||||
|
||||
// Async queue
|
||||
private asyncQueue: AsyncLogQueue | null = null
|
||||
|
||||
// Performance tracking
|
||||
private totalProcessingTime: number = 0
|
||||
private processedLogs: number = 0
|
||||
|
||||
// Metrics module (lazy loaded)
|
||||
private metricsModule: typeof import('./prometheus-metrics') | null = null
|
||||
|
||||
constructor(config: StructuredLoggerConfig) {
|
||||
const envConfig = loadLoggerConfig()
|
||||
this.createdAt = Date.now()
|
||||
|
||||
this.config = {
|
||||
level: config.level,
|
||||
name: config.name || 'app',
|
||||
level: config.level ?? envConfig.level ?? 'info',
|
||||
name: config.name ?? envConfig.name ?? 'app',
|
||||
context: config.context || {},
|
||||
jsonFormat: config.jsonFormat ?? true,
|
||||
jsonFormat: config.jsonFormat ?? envConfig.jsonFormat ?? true,
|
||||
redactFields: [...DEFAULT_REDACT_FIELDS, ...(config.redactFields || [])],
|
||||
externalHook: config.externalHook || (() => {}),
|
||||
includeStackTrace: config.includeStackTrace ?? true,
|
||||
externalHook: config.externalHook,
|
||||
includeStackTrace: config.includeStackTrace ?? envConfig.includeStackTrace ?? true,
|
||||
timezone: config.timezone || 'UTC',
|
||||
enableBuffering: config.enableBuffering ?? envConfig.enableBuffering ?? false,
|
||||
bufferFlushIntervalMs: config.bufferFlushIntervalMs ?? envConfig.bufferFlushIntervalMs ?? 1000,
|
||||
maxBufferSize: config.maxBufferSize ?? envConfig.maxBufferSize ?? 100,
|
||||
enableRateLimiting: config.enableRateLimiting ?? envConfig.enableRateLimiting ?? false,
|
||||
maxLogsPerSecond: config.maxLogsPerSecond ?? envConfig.maxLogsPerSecond ?? 1000,
|
||||
enableAsyncQueue: config.enableAsyncQueue ?? envConfig.enableAsyncQueue ?? false,
|
||||
circuitBreakerThreshold: config.circuitBreakerThreshold ?? 5,
|
||||
circuitBreakerResetMs: config.circuitBreakerResetMs ?? 30000,
|
||||
enableMetrics: config.enableMetrics ?? envConfig.enableMetrics ?? false,
|
||||
}
|
||||
|
||||
this.metrics = {
|
||||
@@ -153,6 +447,45 @@ export class StructuredLogger implements ILogger {
|
||||
silent: 0,
|
||||
},
|
||||
errorsCount: 0,
|
||||
droppedLogs: 0,
|
||||
bufferFlushes: 0,
|
||||
hookFailures: 0,
|
||||
circuitBreakerTrips: 0,
|
||||
avgProcessingTimeMs: 0,
|
||||
}
|
||||
|
||||
// Initialize rate limiter
|
||||
if (this.config.enableRateLimiting) {
|
||||
this.rateLimiter = new RateLimiter(this.config.maxLogsPerSecond)
|
||||
}
|
||||
|
||||
// Initialize circuit breaker for external hook
|
||||
if (this.config.externalHook) {
|
||||
this.circuitBreaker = new CircuitBreaker(
|
||||
this.config.circuitBreakerThreshold,
|
||||
this.config.circuitBreakerResetMs
|
||||
)
|
||||
}
|
||||
|
||||
// Initialize async queue
|
||||
if (this.config.enableAsyncQueue) {
|
||||
this.asyncQueue = new AsyncLogQueue()
|
||||
}
|
||||
|
||||
// Initialize buffer flush timer
|
||||
if (this.config.enableBuffering) {
|
||||
this.bufferFlushTimer = setInterval(() => {
|
||||
this.flushBuffer()
|
||||
}, this.config.bufferFlushIntervalMs)
|
||||
}
|
||||
|
||||
// Load metrics module if enabled
|
||||
if (this.config.enableMetrics) {
|
||||
import('./prometheus-metrics').then(m => {
|
||||
this.metricsModule = m
|
||||
}).catch(() => {
|
||||
// Metrics not available
|
||||
})
|
||||
}
|
||||
}
|
||||
|
||||
@@ -172,6 +505,13 @@ export class StructuredLogger implements ILogger {
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Check if logger has been destroyed
|
||||
*/
|
||||
isDestroyed(): boolean {
|
||||
return this.destroyed
|
||||
}
|
||||
|
||||
/**
|
||||
* Create a child logger with additional context
|
||||
*/
|
||||
@@ -195,7 +535,15 @@ export class StructuredLogger implements ILogger {
|
||||
* Main logging method
|
||||
*/
|
||||
private log(level: LogLevel, obj: unknown, msg?: string): void {
|
||||
if (!this.isLevelEnabled(level)) {
|
||||
if (this.destroyed || !this.isLevelEnabled(level)) {
|
||||
return
|
||||
}
|
||||
|
||||
const startTime = Date.now()
|
||||
|
||||
// Rate limiting check
|
||||
if (this.rateLimiter && !this.rateLimiter.tryAcquire()) {
|
||||
this.metrics.droppedLogs++
|
||||
return
|
||||
}
|
||||
|
||||
@@ -204,14 +552,57 @@ export class StructuredLogger implements ILogger {
|
||||
// Update metrics
|
||||
this.updateMetrics(level)
|
||||
|
||||
// Output
|
||||
this.output(entry)
|
||||
// Process log (sync or async)
|
||||
const processLog = () => {
|
||||
// Buffered output
|
||||
if (this.config.enableBuffering) {
|
||||
this.buffer.push(entry)
|
||||
if (this.buffer.length >= this.config.maxBufferSize) {
|
||||
this.flushBuffer()
|
||||
}
|
||||
} else {
|
||||
this.output(entry)
|
||||
}
|
||||
|
||||
// External hook (async, non-blocking)
|
||||
if (this.config.externalHook) {
|
||||
Promise.resolve(this.config.externalHook(entry)).catch(() => {
|
||||
// Silently ignore hook errors
|
||||
})
|
||||
// External hook with circuit breaker
|
||||
const externalHook = this.config.externalHook
|
||||
if (externalHook && this.circuitBreaker) {
|
||||
this.circuitBreaker.execute(async () => {
|
||||
await Promise.resolve(externalHook(entry))
|
||||
}).catch(() => {
|
||||
this.metrics.hookFailures++
|
||||
if (this.circuitBreaker?.getState() === 'open') {
|
||||
this.metrics.circuitBreakerTrips++
|
||||
}
|
||||
})
|
||||
}
|
||||
|
||||
// Track processing time
|
||||
this.totalProcessingTime += Date.now() - startTime
|
||||
this.processedLogs++
|
||||
this.metrics.avgProcessingTimeMs = this.totalProcessingTime / this.processedLogs
|
||||
}
|
||||
|
||||
// Async or sync processing
|
||||
if (this.asyncQueue) {
|
||||
this.asyncQueue.enqueue(processLog)
|
||||
} else {
|
||||
processLog()
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Flush buffered logs
|
||||
*/
|
||||
flushBuffer(): void {
|
||||
if (this.buffer.length === 0) return
|
||||
|
||||
const entries = this.buffer
|
||||
this.buffer = []
|
||||
this.metrics.bufferFlushes++
|
||||
|
||||
for (const entry of entries) {
|
||||
this.output(entry)
|
||||
}
|
||||
}
|
||||
|
||||
@@ -431,6 +822,21 @@ export class StructuredLogger implements ILogger {
|
||||
return { ...this.metrics }
|
||||
}
|
||||
|
||||
/**
|
||||
* Get comprehensive statistics
|
||||
*/
|
||||
getStatistics(): LoggerStatistics {
|
||||
return {
|
||||
...this.metrics,
|
||||
bufferSize: this.buffer.length,
|
||||
rateLimiterTokens: this.rateLimiter?.getTokens() ?? 0,
|
||||
circuitBreakerState: this.circuitBreaker?.getState() ?? 'closed',
|
||||
queueSize: this.asyncQueue?.getSize() ?? 0,
|
||||
createdAt: this.createdAt,
|
||||
uptimeMs: Date.now() - this.createdAt,
|
||||
}
|
||||
}
|
||||
|
||||
/**
|
||||
* Reset metrics
|
||||
*/
|
||||
@@ -447,7 +853,44 @@ export class StructuredLogger implements ILogger {
|
||||
silent: 0,
|
||||
},
|
||||
errorsCount: 0,
|
||||
droppedLogs: 0,
|
||||
bufferFlushes: 0,
|
||||
hookFailures: 0,
|
||||
circuitBreakerTrips: 0,
|
||||
avgProcessingTimeMs: 0,
|
||||
}
|
||||
this.totalProcessingTime = 0
|
||||
this.processedLogs = 0
|
||||
}
|
||||
|
||||
/**
|
||||
* Destroy the logger and clean up resources
|
||||
* CRITICAL: Call this when done to prevent memory leaks
|
||||
*/
|
||||
destroy(): void {
|
||||
if (this.destroyed) return
|
||||
|
||||
this.destroyed = true
|
||||
|
||||
// Flush remaining buffer
|
||||
this.flushBuffer()
|
||||
|
||||
// Clear buffer flush timer
|
||||
if (this.bufferFlushTimer) {
|
||||
clearInterval(this.bufferFlushTimer)
|
||||
this.bufferFlushTimer = null
|
||||
}
|
||||
|
||||
// Destroy async queue
|
||||
if (this.asyncQueue) {
|
||||
this.asyncQueue.destroy()
|
||||
this.asyncQueue = null
|
||||
}
|
||||
|
||||
// Clear references
|
||||
this.rateLimiter = null
|
||||
this.circuitBreaker = null
|
||||
this.metricsModule = null
|
||||
}
|
||||
}
|
||||
|
||||
|
||||
Reference in New Issue
Block a user