import * as chalk from 'chalk'; import {command, defaultValue, flag, help, multiple, namespace, option} from 'oo-cli'; import {isValidDateOrEpochOrDurationString, parseDate} from '../../lib/parseDate'; import {die} from '../../lib/die'; import {handleInterrupt} from '../../lib/handleInterrupt'; import {TerminalSpinner} from '../../lib/TerminalSpinner'; import {Moria} from '../../lib/Moria'; import {Rivendell} from '../../lib/Rivendell'; import {formatError} from '../../lib/formatError'; import LoggingSearchCriteria = Moria.LoggingSearchCriteria; import LoggingSearchResult = Moria.LoggingSearchResult; import LogEntry = Moria.LogEntry; import LogLevel = Moria.LogLevel; const TAIL_CONFIG = Object.freeze({ // Each pass of the tail query will cover at least tailminWindowMs. // This is done to prevent gaps that may occur (i.e. should encourage at least once delivery). minWindowMs: 30000, // Each pass of the query will be up to Date.now - tailLag // This is done to minimize ordering issue due to log ingest lag lagMs: 15000, queryIntervalMs: 5000, // Size of the dedupe cache. dedupeCacheSize: 5000 }); // Maximum page size for search results. const PAGE_SIZE = 5000; // interval for which to send range queries to loki, longer intervals often time out const INTERVAL = 24 * 60 * 60 * 1000; type LogEntryCallback = (entry: LogEntry) => void; @namespace('app') export class LogsCommand { @option @help('The App ID (e.g. my_app). Either App ID or Build ID must be specified.') public appId?: string; @option @help('The ID of the build. Either App ID or Build ID must be specified. Build IDs are printed by \'ocp app prepare\' command.') public buildId?: string; @option @help('The app version (e.g. 1.0.0)') public appVersion?: string; @option @help('The Tracker ID of the ODP account (required for developers)') public trackerId?: string; @option @help('Show logs for given execution of a job. Use \'ocp jobs list\' command to get the job ID') public jobId?: string; @option @help(`Filter app logs by log level. Valid values: ${Object.values(LogLevel).join(', ')}`) @defaultValue('debug') public level!: string; @option @help('A start time as an ISO string, an epoch timestamp, or relative string (i.e. "5m" for 5 minutes.) Default: 24h') @defaultValue('24h') public from!: string; @option @help('A end time as an ISO string, an epoch timestamp, or relative string (i.e. "5m" for 5 minutes)') public to?: string; @flag @help('Tails the logs') @defaultValue(false) public tail!: boolean; @option @help('String to search for in log messages. Can be specified multiple times.') @multiple public search?: string[]; @option('a') @help('The availability zone that will be targeted (default: us)') private availability: string = ''; @command @help('Fetch app logs') public async logs() { handleInterrupt(); if (!isValidDateOrEpochOrDurationString(this.from)) { die(chalk.red('Invalid "--from" input, should be an ISO string,' + 'an epoch timestamp, or relative string (i.e. "5m" for 5 minutes.')); } const fromDate = parseDate(this.from); let toDate: Date | undefined; if (!this.appId && !this.buildId && !this.jobId) { die('Either App ID, Build ID or Job ID must be specified.'); } if ((this.appId && this.buildId) || (this.appId && this.jobId) || (this.buildId && this.jobId) || (this.appId && this.buildId && this.jobId)) { die('Only App ID, Build ID or Job ID should be specified.'); } if (this.appId && !this.trackerId && !await Rivendell.isAdmin()) { die('Tracker ID must be specified for developer role if App ID is specified.'); } if (this.tail) { if (this.to) { die('Cannot specify --tail if specifying --to'); } } else { if (this.to && !isValidDateOrEpochOrDurationString(this.to)) { die(chalk.red('Invalid "--to" input, should be an ISO string, ' + 'an epoch timestamp, or relative string (i.e. "5m" for 5 minutes.')); } toDate = this.to ? parseDate(this.to) : new Date(); if (fromDate >= toDate) { die(chalk.red('--from must be before --to')); } } this.availability = this.availability ? this.availability : 'us'; const shard = (await Rivendell.shards()).find((_shard) => _shard.id === this.availability); if (!shard) { die('Could not find the specified availability zone.'); } if (this.level) { if (!Object.values(LogLevel).includes(this.level.toUpperCase() as LogLevel)) { die(`Invalid log level. Valid values: ${Object.values(LogLevel).join(', ')}`); } } try { if (this.tail) { await this.tailLogs(shard!, parseDate('5m')); } else { const spinner = new TerminalSpinner().start(''); try { await this.dumpLogs(shard!, fromDate, this.printLogEntry, spinner, toDate); } finally { spinner.stop(); } } } catch (e: any) { die(formatError(e)); } } private printLogEntry = (entry: LogEntry) => { const columns = [ new Date(entry.time).toISOString(), this.formatLevel(entry.level), entry.message ]; console.log(columns.join(' ')); } private formatLevel = (level: LogLevel) => { const padding = 5; switch (level.toUpperCase()) { case LogLevel.DEBUG: { return chalk.blue('DEBUG'.padEnd(padding)); } case LogLevel.INFO: { return chalk.gray('INFO'.padEnd(padding)); } case LogLevel.WARN: { return chalk.yellow('WARN'.padEnd(padding)); } case LogLevel.ERROR: { return chalk.red('ERROR'.padEnd(padding)); } default: return ''; } } private async dumpLogs( shard: Rivendell.Shard, from: Date | number, cb: LogEntryCallback, spinner: TerminalSpinner, to?: Date | number ): Promise { let count = 0; const requests = this.buildRequests(from, to); for (const request of requests) { let result: LoggingSearchResult; do { spinner.update(chalk.gray(`Querying logs until ${request.end ? new Date(request.end).toISOString() : 'now'}`)); result = await Moria.searchLogging(request, shard); result.entries.forEach(cb); request.cursor = result.cursor; count += result.entries.length; } while (result.entries.length > 0); } return count; } private async tailLogs(shard: Rivendell.Shard, from: Date) { const dedupeCache: Set = new Set(); let start = from.valueOf(); const callback = (entry: LogEntry) => { if (!dedupeCache.has(entry.id)) { this.printLogEntry(entry); dedupeCache.add(entry.id); if (dedupeCache.size > TAIL_CONFIG.dedupeCacheSize) { dedupeCache.delete(dedupeCache.entries().next().value); } start = Math.max(start, entry.time); } }; const spinner = new TerminalSpinner().start(''); const query = async () => { const end = Date.now() - TAIL_CONFIG.lagMs; start = Math.min(start, end + TAIL_CONFIG.minWindowMs); await this.dumpLogs(shard, start, callback, spinner, end); spinner.update(chalk.gray('Waiting for more logs...')); setTimeout(query, TAIL_CONFIG.queryIntervalMs); }; await query(); } private buildRequests(from: Date | number, to?: Date | number): LoggingSearchCriteria[] { let start = typeof from === 'number' ? from : from.valueOf(); const end = to ? (typeof to === 'number' ? to : to.valueOf()) : new Date().valueOf(); const requests: LoggingSearchCriteria[] = []; while (start + INTERVAL < end) { requests.push(this.buildRequest(start, start + INTERVAL - 1)); start += INTERVAL; } if (start < end) { requests.push(this.buildRequest(start, to)); } return requests; } private buildRequest(from: Date | number, to?: Date | number): LoggingSearchCriteria { return { context: { appId: this.appId, appVersion: this.appVersion, jobId: this.jobId, trackerId: this.trackerId, buildId: this.buildId, }, pageSize: PAGE_SIZE, start: typeof from === 'number' ? from : from.valueOf(), end: to ? (typeof to === 'number' ? to : to.valueOf()) : undefined, level: this.level as LogLevel, terms: this.search }; } }