diff --git a/unfurler/src/concurrency/ReusablePage.ts b/unfurler/src/concurrency/ReusablePage.ts index f6724b18c..3041711c4 100644 --- a/unfurler/src/concurrency/ReusablePage.ts +++ b/unfurler/src/concurrency/ReusablePage.ts @@ -110,7 +110,7 @@ export default class ReusablePage extends ConcurrencyImplementation { 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}`)); + logger.err(`failed to load frontend during page initialization ${page.clusterGroup}:${page.index}: ` + (e instanceof Error ? e.message : `${e}`)); page.repairRequested = true; } } @@ -131,7 +131,7 @@ export default class ReusablePage extends ConcurrencyImplementation { protected async repairPage(page) { // create a new page - logger.debug(`Repairing page ${page.clusterGroup}:${page.index}`); + logger.info(`Repairing page ${page.clusterGroup}:${page.index}`); const newPage = await this.initPage(); newPage.free = true; // replace the old page diff --git a/unfurler/src/concurrency/ReusableSSRPage.ts b/unfurler/src/concurrency/ReusableSSRPage.ts index 24e9a0f2a..1dedd0958 100644 --- a/unfurler/src/concurrency/ReusableSSRPage.ts +++ b/unfurler/src/concurrency/ReusableSSRPage.ts @@ -49,7 +49,7 @@ export default class ReusableSSRPage extends ReusablePage { await page.goto(defaultUrl, { waitUntil: "networkidle0" }); await page.waitForSelector('meta[property="og:meta:ready"]', { timeout: config.PUPPETEER.RENDER_TIMEOUT || 3000 }); } catch (e) { - logger.err(`failed to load frontend during ssr page initialization: ` + (e instanceof Error ? e.message : `${e}`)); + logger.err(`failed to load frontend during ssr page initialization ${page.clusterGroup}:${page.index}: ` + (e instanceof Error ? e.message : `${e}`)); page.repairRequested = true; } page.free = true; diff --git a/unfurler/src/index.ts b/unfurler/src/index.ts index a81dcbf7a..ae02b8b4c 100644 --- a/unfurler/src/index.ts +++ b/unfurler/src/index.ts @@ -30,6 +30,9 @@ class Server { secureHost = true; canonicalHost: string; + seoQueueLength: number = 0; + unfurlQueueLength: number = 0; + constructor() { this.app = express(); this.mempoolHost = config.MEMPOOL.HTTP_HOST + (config.MEMPOOL.HTTP_PORT ? ':' + config.MEMPOOL.HTTP_PORT : ''); @@ -121,6 +124,7 @@ class Server { } async clusterTask({ page, data: { url, path, action, reqUrl } }) { + const start = Date.now(); try { logger.info(`rendering "${reqUrl}" on tab ${page.clusterGroup}:${page.index}`); const urlParts = parseLanguageUrl(path); @@ -155,6 +159,7 @@ class Server { captureBeyondViewport: false, clip: { width: 1200, height: 600, x: 0, y: 0, scale: 1 }, }); + logger.info(`rendered unfurl img in ${Date.now() - start}ms for "${reqUrl}" on tab ${page.clusterGroup}:${page.index}`); return screenshot; } else if (success === false) { logger.warn(`failed to render ${reqUrl} for ${action} due to client-side error, e.g. requested an invalid txid`); @@ -170,13 +175,14 @@ class Server { } async ssrClusterTask({ page, data: { url, path, action, reqUrl } }) { + const start = Date.now(); try { logger.info(`slurping "${reqUrl}" on tab ${page.clusterGroup}:${page.index}`); const urlParts = parseLanguageUrl(path); if (page.language !== urlParts.lang) { // switch language page.language = urlParts.lang; - const localizedUrl = urlParts.lang ? `${this.mempoolHost}/${urlParts.lang}${urlParts.path}` : `${this.mempoolHost}${urlParts.path}` ; + const localizedUrl = urlParts.lang ? `${this.mempoolHost}/${urlParts.lang}${urlParts.path}` : `${this.mempoolHost}${urlParts.path}`; await page.goto(localizedUrl, { waitUntil: "load" }); } else { const loaded = await page.evaluate(async (path) => { @@ -199,14 +205,17 @@ class Server { return !!window['soft404']; }); if (is404) { + logger.info(`slurp 404 in ${Date.now() - start}ms for "${reqUrl}" on tab ${page.clusterGroup}:${page.index}`); return '404'; } else { let html = await page.content(); + logger.info(`rendered slurp in ${Date.now() - start}ms for "${reqUrl}" on tab ${page.clusterGroup}:${page.index}`); return html; } } catch (e) { if (e instanceof TimeoutError) { let html = await page.content(); + logger.info(`rendered partial slurp in ${Date.now() - start}ms for "${reqUrl}" on tab ${page.clusterGroup}:${page.index}`); return html; } else { logger.err(`failed to render ${reqUrl} for ${action}: ` + (e instanceof Error ? e.message : `${e}`)); @@ -221,6 +230,8 @@ class Server { async renderPreview(req, res) { try { + this.unfurlQueueLength++; + const start = Date.now(); const rawPath = req.params[0]; let img = null; @@ -231,6 +242,7 @@ class Server { // don't bother unless the route is definitely renderable if (rawPath.includes('/preview/') && matchedRoute.render) { img = await this.cluster?.execute({ url: this.mempoolHost + rawPath, path: rawPath, action: 'screenshot', reqUrl: req.url }); + logger.info(`unfurl returned "${req.url}" in ${Date.now() - start}ms | ${this.unfurlQueueLength - 1} tasks in queue`); } else { logger.info('rendering not enabled for page "' + req.url + '"'); } @@ -245,6 +257,8 @@ class Server { } catch (e) { logger.err(e instanceof Error ? e.message : `${e} ${req.params[0]}`); res.status(500).send(e instanceof Error ? e.message : e); + } finally { + this.unfurlQueueLength--; } } @@ -284,7 +298,10 @@ class Server { logger.info('unfurling "' + req.url + '"'); result = await this.renderUnfurlMeta(rawPath); } else { + this.seoQueueLength++; + const start = Date.now(); result = await this.renderSEOPage(rawPath, req.url); + logger.info(`slurp returned "${req.url}" in ${Date.now() - start}ms | ${this.seoQueueLength - 1} tasks in queue`); } if (result && result.length) { if (result === '404') { @@ -298,6 +315,10 @@ class Server { } catch (e) { logger.err(e instanceof Error ? e.message : `${e} ${req.params[0]}`); res.status(500).send(e instanceof Error ? e.message : e); + } finally { + if (!unfurl) { + this.seoQueueLength--; + } } }