diff --git a/unfurler/config.sample.json b/unfurler/config.sample.json index 0e4e8d530..babd9c393 100644 --- a/unfurler/config.sample.json +++ b/unfurler/config.sample.json @@ -1,7 +1,8 @@ { "SERVER": { "HOST": "http://localhost", - "HTTP_PORT": 4201 + "HTTP_PORT": 4201, + "STDOUT_LOG_MIN_PRIORITY": "debug", }, "MEMPOOL": { "HTTP_HOST": "http://localhost", @@ -14,5 +15,12 @@ "EXEC_PATH": "/usr/local/bin/chrome", // optional "MAX_PAGE_AGE": 86400, // maximum lifetime of a page session (in seconds) "RENDER_TIMEOUT": 3000, // timeout for preview image rendering (in ms) (optional) + }, + "SYSLOG": { + "ENABLED": true, + "HOST": "127.0.0.1", + "PORT": 514, + "MIN_PRIORITY": "info", + "FACILITY": "local7" } } diff --git a/unfurler/puppeteer.config.json b/unfurler/puppeteer.config.json index b3a9b7fc4..4d525755e 100644 --- a/unfurler/puppeteer.config.json +++ b/unfurler/puppeteer.config.json @@ -1,5 +1,6 @@ { "headless": true, + "dumpio": true, "defaultViewport": { "width": 1200, "height": 600 diff --git a/unfurler/src/concurrency/ReusablePage.ts b/unfurler/src/concurrency/ReusablePage.ts index ed400d004..4b272afb0 100644 --- a/unfurler/src/concurrency/ReusablePage.ts +++ b/unfurler/src/concurrency/ReusablePage.ts @@ -1,6 +1,7 @@ import * as puppeteer from 'puppeteer'; import ConcurrencyImplementation from 'puppeteer-cluster/dist/concurrency/ConcurrencyImplementation'; import { timeoutExecute } from 'puppeteer-cluster/dist/util'; +import logger from '../logger'; import config from '../config'; const mempoolHost = config.MEMPOOL.HTTP_HOST + (config.MEMPOOL.HTTP_PORT ? ':' + config.MEMPOOL.HTTP_PORT : ''); @@ -43,13 +44,13 @@ export default class ReusablePage extends ConcurrencyImplementation { } this.repairing = true; - console.log('Starting repair'); + logger.info('Starting repair'); try { // will probably fail, but just in case the repair was not necessary await (this.browser).close(); } catch (e) { - console.log('Unable to close browser.'); + logger.warn('Unable to close browser.'); } try { @@ -65,11 +66,17 @@ export default class ReusablePage extends ConcurrencyImplementation { public async init() { this.browser = await this.puppeteer.launch(this.options); + if (this.browser != null) { + const proc = this.browser.process(); + if (proc) { + initBrowserLogging(proc); + } + } const promises = [] for (let i = 0; i < maxConcurrency; i++) { const newPage = await this.initPage(); newPage.index = this.pages.length; - console.log('initialized page ', newPage.index); + logger.info(`initialized page ${newPage.index}`); this.pages.push(newPage); } } @@ -82,15 +89,29 @@ export default class ReusablePage extends ConcurrencyImplementation { const page = await (this.browser as puppeteer.Browser).newPage() as RepairablePage; page.language = null; page.createdAt = Date.now(); - const defaultUrl = mempoolHost + '/preview/block/1'; + let defaultUrl + if (config.MEMPOOL.NETWORK !== 'bisq') { + // preload the preview module + defaultUrl = mempoolHost + '/preview/block/1'; + } else { + // no preview module implemented yet for bisq + defaultUrl = mempoolHost; + } page.on('pageerror', (err) => { page.repairRequested = true; }); - await page.goto(defaultUrl, { waitUntil: "load" }); - await Promise.race([ - page.waitForSelector('meta[property="og:preview:ready"]', { timeout: config.PUPPETEER.RENDER_TIMEOUT || 3000 }).then(() => true), - page.waitForSelector('meta[property="og:preview:fail"]', { timeout: config.PUPPETEER.RENDER_TIMEOUT || 3000 }).then(() => false) - ]) + if (config.MEMPOOL.NETWORK !== 'bisq') { + try { + await page.goto(defaultUrl, { waitUntil: "load" }); + await Promise.race([ + page.waitForSelector('meta[property="og:preview:ready"]', { timeout: config.PUPPETEER.RENDER_TIMEOUT || 3000 }).then(() => true), + page.waitForSelector('meta[property="og:preview:fail"]', { timeout: config.PUPPETEER.RENDER_TIMEOUT || 3000 }).then(() => false) + ]) + } catch (e) { + logger.err(`failed to load frontend during page initialization: ` + (e instanceof Error ? e.message : `${e}`)); + page.repairRequested = true; + } + } page.free = true; return page } @@ -98,7 +119,7 @@ export default class ReusablePage extends ConcurrencyImplementation { protected async createResources(): Promise { const page = this.pages.find(p => p.free); if (!page) { - console.log('no free pages!') + logger.err('no free pages!') throw new Error('no pages available'); } else { page.free = false; @@ -117,7 +138,7 @@ export default class ReusablePage extends ConcurrencyImplementation { try { await page.goto('about:blank', {timeout: 200}); // prevents memory leak (maybe?) } catch (e) { - console.log('unexpected page repair error'); + logger.err('unexpected page repair error'); } await page.close(); return newPage; @@ -161,3 +182,26 @@ export default class ReusablePage extends ConcurrencyImplementation { }; } } + +function initBrowserLogging(proc) { + if (proc.stderr && proc.stdout) { + proc.on('error', msg => { + logger.err('BROWSER ERROR ' + msg); + }) + proc.stderr.on('data', buf => { + const msg = String(buf); + // For some reason everything (including js console logs) is piped to stderr + // so this kludge splits logs back into their priority levels + if (msg.includes(':INFO:')) { + logger.info('BROWSER' + msg, true); + } else if (msg.includes(':WARNING:')) { + logger.warn('BROWSER' + msg, true); + } else { + logger.err('BROWSER' + msg, true); + } + }) + proc.stdout.on('data', buf => { + logger.info('BROWSER' + String(buf)); + }) + } +} diff --git a/unfurler/src/config.ts b/unfurler/src/config.ts index c04f58007..76bc2a75f 100644 --- a/unfurler/src/config.ts +++ b/unfurler/src/config.ts @@ -4,6 +4,7 @@ interface IConfig { SERVER: { HOST: 'http://localhost'; HTTP_PORT: number; + STDOUT_LOG_MIN_PRIORITY: string; }; MEMPOOL: { HTTP_HOST: string; @@ -17,12 +18,20 @@ interface IConfig { MAX_PAGE_AGE?: number; RENDER_TIMEOUT?: number; }; + SYSLOG: { + ENABLED: boolean; + HOST: string; + PORT: number; + MIN_PRIORITY: 'emerg' | 'alert' | 'crit' | 'err' | 'warn' | 'notice' | 'info' | 'debug'; + FACILITY: string; + }; } const defaults: IConfig = { 'SERVER': { 'HOST': 'http://localhost', 'HTTP_PORT': 4201, + 'STDOUT_LOG_MIN_PRIORITY': 'debug', }, 'MEMPOOL': { 'HTTP_HOST': 'http://localhost', @@ -32,18 +41,27 @@ const defaults: IConfig = { 'ENABLED': true, 'CLUSTER_SIZE': 1, }, + 'SYSLOG': { + 'ENABLED': true, + 'HOST': '127.0.0.1', + 'PORT': 514, + 'MIN_PRIORITY': 'info', + 'FACILITY': 'local7' + }, }; class Config implements IConfig { SERVER: IConfig['SERVER']; MEMPOOL: IConfig['MEMPOOL']; PUPPETEER: IConfig['PUPPETEER']; + SYSLOG: IConfig['SYSLOG']; constructor() { const configs = this.merge(configFile, defaults); this.SERVER = configs.SERVER; this.MEMPOOL = configs.MEMPOOL; this.PUPPETEER = configs.PUPPETEER; + this.SYSLOG = configs.SYSLOG; } merge = (...objects: object[]): IConfig => { diff --git a/unfurler/src/index.ts b/unfurler/src/index.ts index 4ae1d088e..60126863d 100644 --- a/unfurler/src/index.ts +++ b/unfurler/src/index.ts @@ -7,6 +7,7 @@ import { Cluster } from 'puppeteer-cluster'; import ReusablePage from './concurrency/ReusablePage'; import { parseLanguageUrl } from './language/lang'; import { matchRoute } from './routes'; +import logger from './logger'; const puppeteerConfig = require('../puppeteer.config.json'); if (config.PUPPETEER.EXEC_PATH) { @@ -55,7 +56,7 @@ class Server { this.server = http.createServer(this.app); this.server.listen(config.SERVER.HTTP_PORT, () => { - console.log(`Mempool Unfurl Server is running on port ${config.SERVER.HTTP_PORT}`); + logger.info(`Mempool Unfurl Server is running on port ${config.SERVER.HTTP_PORT}`); }); } @@ -102,20 +103,23 @@ class Server { // wait for preview component to initialize await page.waitForSelector('meta[property="og:preview:loading"]', { timeout: config.PUPPETEER.RENDER_TIMEOUT || 3000 }) - let success = false; + let success; success = await Promise.race([ page.waitForSelector('meta[property="og:preview:ready"]', { timeout: config.PUPPETEER.RENDER_TIMEOUT || 3000 }).then(() => true), page.waitForSelector('meta[property="og:preview:fail"]', { timeout: config.PUPPETEER.RENDER_TIMEOUT || 3000 }).then(() => false) ]) - if (success) { + if (success === true) { const screenshot = await page.screenshot(); return screenshot; + } else if (success === false) { + logger.warn(`failed to render page preview for ${action} due to client-side error, e.g. requested an invalid txid`); + page.repairRequested = true; } else { - console.log(`failed to render page preview for ${action} due to client-side error. probably requested an invalid ID`); + logger.warn(`failed to render page preview for ${action} due to puppeteer timeout`); page.repairRequested = true; } } catch (e) { - console.log(`failed to render page for ${action}`, e instanceof Error ? e.message : e); + logger.err(`failed to render page for ${action}: ` + (e instanceof Error ? e.message : `${e}`)); page.repairRequested = true; } } @@ -150,7 +154,7 @@ class Server { res.send(img); } } catch (e) { - console.log(e); + logger.err(e instanceof Error ? e.message : `${e}`); res.status(500).send(e instanceof Error ? e.message : e); } } @@ -202,7 +206,7 @@ class Server { const server = new Server(); process.on('SIGTERM', async () => { - console.info('Shutting down Mempool Unfurl Server'); + logger.info('Shutting down Mempool Unfurl Server'); await server.stopServer(); process.exit(0); }); diff --git a/unfurler/src/logger.ts b/unfurler/src/logger.ts new file mode 100644 index 000000000..e3b653b56 --- /dev/null +++ b/unfurler/src/logger.ts @@ -0,0 +1,142 @@ +import config from './config'; +import * as dgram from 'dgram'; + +class Logger { + static priorities = { + emerg: 0, + alert: 1, + crit: 2, + err: 3, + warn: 4, + notice: 5, + info: 6, + debug: 7 + }; + static facilities = { + kern: 0, + user: 1, + mail: 2, + daemon: 3, + auth: 4, + syslog: 5, + lpr: 6, + news: 7, + uucp: 8, + local0: 16, + local1: 17, + local2: 18, + local3: 19, + local4: 20, + local5: 21, + local6: 22, + local7: 23 + }; + + // @ts-ignore + public emerg: ((msg: string, quiet: boolean = false) => void); + // @ts-ignore + public alert: ((msg: string, quiet: boolean = false) => void); + // @ts-ignore + public crit: ((msg: string, quiet: boolean = false) => void); + // @ts-ignore + public err: ((msg: string, quiet: boolean = false) => void); + // @ts-ignore + public warn: ((msg: string, quiet: boolean = false) => void); + // @ts-ignore + public notice: ((msg: string, quiet: boolean = false) => void); + // @ts-ignore + public info: ((msg: string, quiet: boolean = false) => void); + // @ts-ignore + public debug: ((msg: string, quiet: boolean = false) => void); + + private name = 'mempool'; + private client: dgram.Socket; + private network: string; + + constructor() { + let prio; + for (prio in Logger.priorities) { + if (true) { + this.addprio(prio); + } + } + this.client = dgram.createSocket('udp4'); + this.network = this.getNetwork(); + } + + private addprio(prio): void { + this[prio] = (function(_this) { + return function(msg, quiet) { + return _this.msg(prio, msg, quiet); + }; + })(this); + } + + private getNetwork(): string { + return config.MEMPOOL.NETWORK || 'bitcoin'; + } + + private msg(priority, msg, quiet) { + let consolemsg, prionum, syslogmsg; + if (typeof msg === 'string' && msg.length > 0) { + while (msg[msg.length - 1].charCodeAt(0) === 10) { + msg = msg.slice(0, msg.length - 1); + } + } + const network = this.network ? ' <' + this.network + '-unfurler>' : ''; + prionum = Logger.priorities[priority] || Logger.priorities.info; + consolemsg = `${this.ts()} [${process.pid}] ${priority.toUpperCase()}:${network} ${msg}`; + + if (config.SYSLOG.ENABLED && Logger.priorities[priority] <= Logger.priorities[config.SYSLOG.MIN_PRIORITY]) { + syslogmsg = `<${(Logger.facilities[config.SYSLOG.FACILITY] * 8 + prionum)}> ${this.name}[${process.pid}]: ${priority.toUpperCase()}${network} ${msg}`; + this.syslog(syslogmsg); + } + if (quiet || Logger.priorities[priority] > Logger.priorities[config.SERVER.STDOUT_LOG_MIN_PRIORITY]) { + return; + } + if (priority === 'warning') { + priority = 'warn'; + } + if (priority === 'debug') { + priority = 'info'; + } + if (priority === 'err') { + priority = 'error'; + } + return (console[priority] || console.error)(consolemsg); + } + + private syslog(msg) { + let msgbuf; + msgbuf = Buffer.from(msg); + this.client.send(msgbuf, 0, msgbuf.length, config.SYSLOG.PORT, config.SYSLOG.HOST, function(err, bytes) { + if (err) { + console.log(err); + } + }); + } + + private leadZero(n: number): number | string { + if (n < 10) { + return '0' + n; + } + return n; + } + + private ts() { + let day, dt, hours, minutes, month, months, seconds; + dt = new Date(); + hours = this.leadZero(dt.getHours()); + minutes = this.leadZero(dt.getMinutes()); + seconds = this.leadZero(dt.getSeconds()); + month = dt.getMonth(); + day = dt.getDate(); + if (day < 10) { + day = ' ' + day; + } + months = ['Jan', 'Feb', 'Mar', 'Apr', 'May', 'Jun', 'Jul', 'Aug', 'Sep', 'Oct', 'Nov', 'Dec']; + return months[month] + ' ' + day + ' ' + hours + ':' + minutes + ':' + seconds; + } +} + +export default new Logger();