2018-08-27 00:17:11 +00:00
|
|
|
import * as Bluebird from 'bluebird';
|
|
|
|
import * as _ from 'lodash';
|
|
|
|
|
2019-04-01 14:55:15 +00:00
|
|
|
import DB from './db';
|
2018-08-27 00:17:11 +00:00
|
|
|
import { EventTracker } from './event-tracker';
|
2019-01-23 19:24:57 +00:00
|
|
|
import Docker from './lib/docker-utils';
|
2018-08-27 00:17:11 +00:00
|
|
|
import { LogType } from './lib/log-types';
|
2018-12-24 13:16:35 +00:00
|
|
|
import { writeLock } from './lib/update-lock';
|
2018-10-09 11:02:38 +00:00
|
|
|
import {
|
2019-01-23 19:26:01 +00:00
|
|
|
BalenaLogBackend,
|
2019-04-01 13:27:12 +00:00
|
|
|
ContainerLogs,
|
2018-10-09 11:02:38 +00:00
|
|
|
LocalLogBackend,
|
|
|
|
LogBackend,
|
|
|
|
LogMessage,
|
2019-04-01 13:27:12 +00:00
|
|
|
} from './logging';
|
2019-05-28 13:27:56 +00:00
|
|
|
import LogMonitor from './logging/monitor';
|
2018-08-27 00:17:11 +00:00
|
|
|
|
|
|
|
interface LoggerSetupOptions {
|
|
|
|
apiEndpoint: string;
|
|
|
|
uuid: string;
|
|
|
|
deviceApiKey: string;
|
2018-12-13 14:14:15 +00:00
|
|
|
unmanaged: boolean;
|
2018-08-27 00:17:11 +00:00
|
|
|
enableLogs: boolean;
|
2018-10-09 11:02:38 +00:00
|
|
|
localMode: boolean;
|
2018-08-27 00:17:11 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
type LogEventObject = Dictionary<any> | null;
|
|
|
|
|
2018-09-18 14:36:59 +00:00
|
|
|
interface LoggerConstructOptions {
|
2019-04-01 14:55:15 +00:00
|
|
|
db: DB;
|
2018-09-18 14:36:59 +00:00
|
|
|
eventTracker: EventTracker;
|
|
|
|
}
|
|
|
|
|
2018-08-27 00:17:11 +00:00
|
|
|
export class Logger {
|
|
|
|
private backend: LogBackend | null = null;
|
2018-10-18 18:52:35 +00:00
|
|
|
private balenaBackend: BalenaLogBackend | null = null;
|
2018-10-09 11:02:38 +00:00
|
|
|
private localBackend: LocalLogBackend | null = null;
|
|
|
|
|
2018-08-27 00:17:11 +00:00
|
|
|
private eventTracker: EventTracker;
|
2019-04-01 14:55:15 +00:00
|
|
|
private db: DB;
|
2019-04-01 13:27:12 +00:00
|
|
|
private containerLogs: { [containerId: string]: ContainerLogs } = {};
|
2019-05-28 13:27:56 +00:00
|
|
|
private logMonitor: LogMonitor;
|
2018-08-27 00:17:11 +00:00
|
|
|
|
2019-04-01 14:55:15 +00:00
|
|
|
public constructor({ db, eventTracker }: LoggerConstructOptions) {
|
2018-08-27 00:17:11 +00:00
|
|
|
this.backend = null;
|
|
|
|
this.eventTracker = eventTracker;
|
2019-04-01 14:55:15 +00:00
|
|
|
this.db = db;
|
2019-05-28 13:27:56 +00:00
|
|
|
this.logMonitor = new LogMonitor(db);
|
2018-08-27 00:17:11 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
public init({
|
|
|
|
apiEndpoint,
|
|
|
|
uuid,
|
|
|
|
deviceApiKey,
|
2018-12-13 14:14:15 +00:00
|
|
|
unmanaged,
|
2018-08-27 00:17:11 +00:00
|
|
|
enableLogs,
|
2018-10-09 11:02:38 +00:00
|
|
|
localMode,
|
2018-11-02 14:17:58 +00:00
|
|
|
}: LoggerSetupOptions) {
|
2018-10-18 18:52:35 +00:00
|
|
|
this.balenaBackend = new BalenaLogBackend(apiEndpoint, uuid, deviceApiKey);
|
2018-10-09 11:02:38 +00:00
|
|
|
this.localBackend = new LocalLogBackend();
|
|
|
|
|
2018-10-18 18:52:35 +00:00
|
|
|
this.backend = localMode ? this.localBackend : this.balenaBackend;
|
2018-10-09 11:02:38 +00:00
|
|
|
|
2018-12-13 14:14:15 +00:00
|
|
|
this.backend.unmanaged = unmanaged;
|
2018-08-27 20:58:20 +00:00
|
|
|
this.backend.publishEnabled = enableLogs;
|
2018-08-27 00:17:11 +00:00
|
|
|
}
|
|
|
|
|
2018-10-09 11:02:38 +00:00
|
|
|
public switchBackend(localMode: boolean) {
|
|
|
|
if (localMode) {
|
|
|
|
// Use the local mode backend
|
|
|
|
this.backend = this.localBackend;
|
|
|
|
console.log('Switching logging backend to LocalLogBackend');
|
|
|
|
} else {
|
2018-10-18 18:52:35 +00:00
|
|
|
// Use the balena backend
|
|
|
|
this.backend = this.balenaBackend;
|
|
|
|
console.log('Switching logging backend to BalenaLogBackend');
|
2018-10-09 11:02:38 +00:00
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
public getLocalBackend(): LocalLogBackend {
|
|
|
|
// TODO: Think about this interface a little better, it would be
|
|
|
|
// nicer to proxy the logs via the logger module
|
|
|
|
if (this.localBackend == null) {
|
|
|
|
// TODO: Type this as an internal inconsistency error
|
|
|
|
throw new Error('Local backend logger is not defined.');
|
|
|
|
}
|
|
|
|
return this.localBackend;
|
|
|
|
}
|
|
|
|
|
2018-08-27 00:17:11 +00:00
|
|
|
public enable(value: boolean = true) {
|
|
|
|
if (this.backend != null) {
|
|
|
|
this.backend.publishEnabled = value;
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
public logDependent(message: LogMessage, device: { uuid: string }) {
|
|
|
|
if (this.backend != null) {
|
|
|
|
message.uuid = device.uuid;
|
|
|
|
this.backend.log(message);
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
public log(message: LogMessage) {
|
|
|
|
if (this.backend != null) {
|
|
|
|
this.backend.log(message);
|
|
|
|
}
|
|
|
|
}
|
|
|
|
|
|
|
|
public logSystemMessage(
|
|
|
|
message: string,
|
|
|
|
eventObj?: LogEventObject,
|
|
|
|
eventName?: string,
|
2019-02-14 13:24:50 +00:00
|
|
|
track: boolean = true,
|
2018-08-27 00:17:11 +00:00
|
|
|
) {
|
|
|
|
const msgObj: LogMessage = { message, isSystem: true };
|
|
|
|
if (eventObj != null && eventObj.error != null) {
|
|
|
|
msgObj.isStdErr = true;
|
|
|
|
}
|
|
|
|
this.log(msgObj);
|
2019-02-14 13:24:50 +00:00
|
|
|
if (track) {
|
|
|
|
this.eventTracker.track(
|
|
|
|
eventName != null ? eventName : message,
|
|
|
|
eventObj != null ? eventObj : {},
|
|
|
|
);
|
|
|
|
}
|
2018-08-27 00:17:11 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
public lock(containerId: string): Bluebird.Disposer<() => void> {
|
2018-12-24 13:16:35 +00:00
|
|
|
return writeLock(containerId).disposer(release => {
|
2018-11-02 14:17:58 +00:00
|
|
|
release();
|
|
|
|
});
|
2018-08-27 00:17:11 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
public attach(
|
|
|
|
docker: Docker,
|
|
|
|
containerId: string,
|
2019-01-24 16:50:40 +00:00
|
|
|
serviceInfo: { serviceId: number; imageId: number },
|
2018-08-27 00:17:11 +00:00
|
|
|
): Bluebird<void> {
|
2019-04-01 13:27:12 +00:00
|
|
|
// First detect if we already have an attached log stream
|
|
|
|
// for this container
|
|
|
|
if (containerId in this.containerLogs) {
|
|
|
|
return Bluebird.resolve();
|
|
|
|
}
|
|
|
|
|
2019-04-01 14:55:15 +00:00
|
|
|
return Bluebird.using(this.lock(containerId), async () => {
|
2019-04-01 13:27:12 +00:00
|
|
|
const logs = new ContainerLogs(containerId, docker);
|
|
|
|
this.containerLogs[containerId] = logs;
|
|
|
|
logs.on('error', err => {
|
|
|
|
console.error(`Container log retrieval error: ${err}`);
|
|
|
|
delete this.containerLogs[containerId];
|
|
|
|
});
|
2019-04-01 14:55:15 +00:00
|
|
|
logs.on('log', async logMessage => {
|
2019-04-01 13:27:12 +00:00
|
|
|
this.log(_.merge({}, serviceInfo, logMessage));
|
2019-04-01 14:55:15 +00:00
|
|
|
|
|
|
|
// Take the timestamp and set it in the database as the last
|
|
|
|
// log sent for this
|
2019-05-28 13:27:56 +00:00
|
|
|
this.logMonitor.updateContainerSentTimestamp(
|
|
|
|
containerId,
|
|
|
|
logMessage.timestamp,
|
|
|
|
);
|
2018-11-02 14:17:58 +00:00
|
|
|
});
|
2019-04-01 14:55:15 +00:00
|
|
|
|
2019-04-01 13:27:12 +00:00
|
|
|
logs.on('closed', () => delete this.containerLogs[containerId]);
|
2019-04-01 14:55:15 +00:00
|
|
|
|
2019-05-28 13:27:56 +00:00
|
|
|
const lastSentTimestamp = await this.logMonitor.getContainerSentTimestamp(
|
|
|
|
containerId,
|
|
|
|
);
|
2019-04-01 14:55:15 +00:00
|
|
|
return logs.attach(lastSentTimestamp);
|
2018-08-27 00:17:11 +00:00
|
|
|
});
|
|
|
|
}
|
|
|
|
|
2019-02-14 13:24:50 +00:00
|
|
|
public logSystemEvent(
|
|
|
|
logType: LogType,
|
|
|
|
obj: LogEventObject,
|
|
|
|
track: boolean = true,
|
|
|
|
): void {
|
2018-08-27 00:17:11 +00:00
|
|
|
let message = logType.humanName;
|
|
|
|
const objectName = this.objectNameForLogs(obj);
|
|
|
|
if (objectName != null) {
|
|
|
|
message += ` '${objectName}'`;
|
|
|
|
}
|
|
|
|
if (obj && obj.error != null) {
|
|
|
|
let errorMessage = obj.error.message;
|
|
|
|
if (_.isEmpty(errorMessage)) {
|
2019-02-13 15:44:42 +00:00
|
|
|
errorMessage =
|
|
|
|
obj.error.name !== 'Error' ? obj.error.name : 'Unknown cause';
|
2018-08-27 00:17:11 +00:00
|
|
|
console.error('Warning: invalid error message', obj.error);
|
|
|
|
}
|
|
|
|
message += ` due to '${errorMessage}'`;
|
|
|
|
}
|
2019-02-14 13:24:50 +00:00
|
|
|
this.logSystemMessage(message, obj, logType.eventName, track);
|
2018-08-27 00:17:11 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
public logConfigChange(
|
|
|
|
config: { [configName: string]: string },
|
2018-11-02 15:37:47 +00:00
|
|
|
{ success = false, err }: { success?: boolean; err?: Error } = {},
|
2018-08-27 00:17:11 +00:00
|
|
|
) {
|
|
|
|
const obj: LogEventObject = { config };
|
|
|
|
let message: string;
|
|
|
|
let eventName: string;
|
|
|
|
if (success) {
|
|
|
|
message = `Applied configuration change ${JSON.stringify(config)}`;
|
|
|
|
eventName = 'Apply config change success';
|
2018-11-02 14:17:58 +00:00
|
|
|
} else if (err != null) {
|
2018-08-27 00:17:11 +00:00
|
|
|
message = `Error applying configuration change: ${err}`;
|
|
|
|
eventName = 'Apply config change error';
|
|
|
|
obj.error = err;
|
|
|
|
} else {
|
2018-09-13 13:44:20 +00:00
|
|
|
message = `Applying configuration change ${JSON.stringify(config)}`;
|
2018-08-27 00:17:11 +00:00
|
|
|
eventName = 'Apply config change in progress';
|
|
|
|
}
|
|
|
|
|
|
|
|
this.logSystemMessage(message, obj, eventName);
|
|
|
|
}
|
|
|
|
|
2019-04-01 14:55:15 +00:00
|
|
|
public async clearOutOfDateDBLogs(containerIds: string[]) {
|
|
|
|
console.log('Performing database cleanup for container log timestamps');
|
|
|
|
await this.db
|
|
|
|
.models('containerLogs')
|
|
|
|
.whereNotIn('containerId', containerIds)
|
|
|
|
.delete();
|
|
|
|
}
|
|
|
|
|
2018-08-27 00:17:11 +00:00
|
|
|
private objectNameForLogs(eventObj: LogEventObject): string | null {
|
|
|
|
if (eventObj == null) {
|
|
|
|
return null;
|
|
|
|
}
|
2018-11-02 14:17:58 +00:00
|
|
|
if (
|
|
|
|
eventObj.service != null &&
|
2018-08-27 00:17:11 +00:00
|
|
|
eventObj.service.serviceName != null &&
|
2018-10-12 12:44:23 +00:00
|
|
|
eventObj.service.config != null &&
|
2018-09-18 14:36:59 +00:00
|
|
|
eventObj.service.config.image != null
|
2018-08-27 00:17:11 +00:00
|
|
|
) {
|
2018-09-18 14:36:59 +00:00
|
|
|
return `${eventObj.service.serviceName} ${eventObj.service.config.image}`;
|
2018-08-27 00:17:11 +00:00
|
|
|
}
|
|
|
|
|
|
|
|
if (eventObj.image != null) {
|
|
|
|
return eventObj.image.name;
|
|
|
|
}
|
|
|
|
|
|
|
|
if (eventObj.network != null && eventObj.network.name != null) {
|
|
|
|
return eventObj.network.name;
|
|
|
|
}
|
|
|
|
|
|
|
|
if (eventObj.volume != null && eventObj.volume.name != null) {
|
|
|
|
return eventObj.volume.name;
|
|
|
|
}
|
|
|
|
|
2018-09-18 14:36:59 +00:00
|
|
|
if (eventObj.fields != null) {
|
|
|
|
return eventObj.fields.join(',');
|
|
|
|
}
|
|
|
|
|
2018-08-27 00:17:11 +00:00
|
|
|
return null;
|
|
|
|
}
|
|
|
|
}
|
2018-12-20 11:13:53 +00:00
|
|
|
|
|
|
|
export default Logger;
|