'use strict'; // Disable trace handling inside trace handler to avoid recursion // Set to true to prevent action till loading is complete -- set to false at end let reentrantDisable = true; let lazyloadDone = false; let path; let fs; // ///////////////////////////// // Trace calls /* *Check and emit time travel trace * -- invoke remoteTraceManagerObj functions as needed. *@emitKind string matching one of the emitOption flags *@optInfo additional info we want to pass in (error code for emitOnExit) *@result 're-entrant' 'disabled', 'no-sample', 'fail', 'success' */ function emitTrace(emitKind, optInfo) { const res = emitTrace_helper(emitKind, optInfo); if (res.flag === 'success') { // This is an intentional programatic breakpoint // -- it is only triggerable in --replay-debug mode debugger; /* TTD_DEBUG_BREAKPOINT */ // eslint-disable-line no-debugger } res.action(); } exports.emitTrace = emitTrace; function buildTraceResult(flagv, actionv) { const realAction = actionv || function() { }; return { flag: flagv, action: realAction }; } function emitTrace_helper(emitKind, optInfo) { if (reentrantDisable) { return buildTraceResult('re-entrant'); } reentrantDisable = true; try { if (!global.enabledDiagnosticsTrace || !global.enabledDiagnosticsTrace()) { return buildTraceResult('disabled'); } if (!checkGlobalShouldEmit(emitKind, optInfo)) { return buildTraceResult('no-sample'); } if (!lazyloadDone) { path = require('path'); fs = require('fs'); lazyloadDone = true; } // Process a synchronous write action for a unique trace bin // -- otherwise a async action on a multiple trace bin let sampleRes = buildTraceResult('no-sample'); if (emitKind === 'emitOnExit' || emitKind === 'emitOnException' || emitKind === 'emitOnSigInt') { sampleRes = emitSyncTraceKind(emitKind, optInfo); } else { sampleRes = emitAsyncTraceKind(emitKind); } if (sampleRes.flag === 'success') { updateGlobalSampleStats(emitKind); } return sampleRes; } catch (ex) { process.stderr.write('Failed in emitTrace with: ' + ex); return buildTraceResult('fail'); } finally { reentrantDisable = false; } } // // // Helpers for trace calls function emitSyncTraceKind(emitKind, optInfo) { // build up trace name let traceName = emitKind; if (emitKind === 'emitOnExit') { traceName += ('_code-' + optInfo); } // invoke the trace writer and remote manager if needed const resolvedPath = createTraceLogTarget(traceName); if (!resolvedPath) { return buildTraceResult('fail'); } function action() { try { process.stderr.write(` Write error trace to: ${resolvedPath}\n`); global.emitTTDLog(resolvedPath); if (emitOptions.remoteTraceManagerObj && emitOptions.remoteTraceManagerObj.uploadTraceSync) { emitOptions.remoteTraceManagerObj.uploadTraceSync(resolvedPath); } } catch (ex) { process.stderr.write('Failed in emitTrace with: ' + ex); } } return buildTraceResult('success', action); } function emitAsyncTraceKind(emitKind) { // get trace stack and check if we want to emit const stk = generateFuzzyStack(emitKind); const entry = checkBinShouldEmit(stk); if (!entry) { return buildTraceResult('no-sample'); } // build up trace name const traceBucketName = `${emitKind}_${stk.fbin}_bucket-${entry.bucketId}`; const traceDirName = `trace-${entry.traceCtr}`; const traceName = path.join(traceBucketName, traceDirName); // invoke the trace writer and remote manager if needed const resolvedPath = createTraceLogTarget(traceName); if (!resolvedPath) { return buildTraceResult('fail'); } function action() { try { process.stderr.write(` Write error trace to: ${resolvedPath}\n`); global.emitTTDLog(resolvedPath); if (emitOptions.remoteTraceManagerObj && emitOptions.remoteTraceManagerObj.uploadTraceAsync) { emitOptions.remoteTraceManagerObj.uploadTraceAsync(resolvedPath); } } catch (ex) { process.stderr.write('Failed in emitTrace with: ' + ex); } } // update the bin stats as needed updateEmitInfo(entry, resolvedPath); return buildTraceResult('success', action); } // create a directory for emitting the trace (if possible) and return it function createTraceLogTarget(tracename) { const traceRootDir = emitOptions.localTraceDirectory || path.dirname(process.mainModule.filename); // Add the PID to the trace name tracename = `${tracename}_pid${process.pid}`; const resolvedTracePath = path.resolve(traceRootDir, '_diagnosticTraces', tracename); // ensure directory exists and is empty... const ok = ensureTraceTarget(resolvedTracePath); if (!ok) { return undefined; } return resolvedTracePath; } // ensure directory exists and is empty... function ensureTraceTarget(pth) { // I don't like this and don't want it to be happening so I am going to bail if (!path.isAbsolute(pth)) { return false; } const okdir = createTargetDirectory(pth); if (!okdir) { return false; } return deleteTargetDirectoryContents(pth); } function createTargetDirectory(pth) { // see if it just exists and, if so, just return true const accessok = fs.constants.R_OK | fs.constants.W_OK | fs.constants.X_OK; try { fs.accessSync(pth, accessok); if (fs.statSync(pth).isDirectory()) { return true; } } catch (ei) { } // walk up the directory to see where the first valid part of the path is let prefixPath = pth; const suffixPaths = []; let baseFound = false; do { // check for bad prefix if (prefixPath === path.dirname(prefixPath)) { process.stderr.write(`Failed prefix: ${pth} -> ${prefixPath}\n`); return false; } suffixPaths.push(path.basename(prefixPath)); // reverse order prefixPath = path.dirname(prefixPath); try { fs.accessSync(prefixPath, accessok); baseFound = fs.statSync(prefixPath).isDirectory(); } catch (ei) { } } while (!baseFound); // now extend the prefix with all the suffix parts while (suffixPaths.length > 0) { try { prefixPath = path.resolve(prefixPath, suffixPaths.pop()); fs.mkdirSync(prefixPath); } catch (ec) { process.stderr.write(`Failed creating trace directory : ${ec}\n`); return false; } } return true; } function deleteTargetDirectoryContents(pth) { try { const items = fs.readdirSync(pth); for (var i = 0; i < items.length; i++) { const fpath = path.resolve(pth, items[i]); const stats = fs.lstatSync(fpath); if (stats.isFile()) { fs.unlinkSync(fpath); } else if (stats.isDirectory()) { const recok = deleteTargetDirectoryContents(fpath); if (!recok) { return false; } fs.rmdirSync(fpath); } else { return false; // something strange in here. } } } catch (ex) { process.stderr.write(`Failed cleaning directory contents: ${ex}\n`); return false; } return true; } // after we take a sample update the sampling stats function updateGlobalSampleStats(eventKind) { currentSampleRate[eventKind] *= emitOptions.backoffFactors[eventKind]; const updateTime = new Date(); emitMinTimeValue.emitOnLogWarn = new Date(updateTime); emitMinTimeValue.emitOnLogError = new Date(updateTime); if (eventKind === 'emitOnAssert') { emitMinTimeValue.emitOnAssert = updateTime; } } // ///////////////////////////// // Trace emit manager code const emitOptions = { emitOnExit: 'error', // emit a trace on exit -- off, error, all emitOnException: true, // emit a trace on uncaught execption emitOnSigInt: true, // emit a trace on sigint emitOnLogWarn: true, // check for trace emit on console.warn emitOnLogError: true, // check for trace emit on console.error emitOnAssert: true, // check for trace emit on console.assert or assert globalMinInterval: 500, // min interval between console/assert trace emits globalBackoffCancelInterval: 5000, // time when we reset the backoff interval // The probability that we sample on the first warn/error/assert encountered initialRates: { emitOnLogWarn: 0.25, emitOnLogError: 0.25, emitOnAssert: 1.0 }, // The baseline background probability that we sample traces baselineRates: { emitOnLogWarn: 0.25, emitOnLogError: 0.25, emitOnAssert: 1.0 }, // backoff factor to apply backoffFactors: { emitOnLogWarn: 0.25, emitOnLogError: 0.5, emitOnAssert: 0.5 }, binMaxSampled: 10, // Max number of traces to take per stack bin binBackoffFactor: 0.5, // sample probability #preserved * binBackoffFactor localTraceDirectory: undefined, // The root directory for storing traces remoteTraceManagerObj: undefined // manager object for remote trace support }; const callStackEmitInfoMap = new Map(); let bucketCtr = 0; const emitMinTimeValue = { emitOnLogWarn: new Date(0), emitOnLogError: new Date(0), emitOnAssert: new Date(0) }; const currentSampleRate = {}; for (const srp in emitOptions.initialRates) { currentSampleRate[srp] = emitOptions.initialRates[srp]; } /* *Update emitOptions from the given options object */ function setOptions(optionsObj) { for (const opt in optionsObj) { // TODO: need more error checking on the validity of the option values emitOptions[opt] = optionsObj[opt]; } for (const srp in emitOptions.initialRates) { currentSampleRate[srp] = emitOptions.initialRates[srp]; } } exports.setOptions = setOptions; /* *Do a preliminary check if the emitKind is even enabled and to do sampling. *@emitKind string matching one of the emitOption flags *@optInfo additional info we want to pass in (error code for emitOnExit) *@result true if we may want to sample false if we definitely do not */ function checkGlobalShouldEmit(emitKind, optInfo) { // Check if the flag is enabled if (emitKind === 'emitOnExit') { if (emitOptions.emitOnExit === 'all') { return true; } else { return (emitOptions.emitOnExit === 'error') && (optInfo !== 0); } } else if (emitKind === 'emitOnException' || emitKind === 'emitOnSigInt') { return emitOptions[emitKind]; } else { if (!emitOptions[emitKind]) { return false; } const sampleInterval = new Date() - emitMinTimeValue[emitKind]; // Don't sample too often no matter what (or we can basically live lock) if (sampleInterval < emitOptions.globalMinInterval) { return false; } // Relax our global rate if it has been a while if (sampleInterval >= emitOptions.globalBackoffCancelInterval) { const currRate = currentSampleRate[emitKind]; const blRate = emitOptions.baselineRates[emitKind]; currentSampleRate[emitKind] = Math.max(currRate, blRate); } // Probabalistic check if we want to do sample new trace return Math.random() < currentSampleRate[emitKind]; } } /* *Given a fuzzy stack see if we want to write a trace for the call *@fuzzyStack is the stack produced by getFuzzyCallStack *@result if we want to sample return the entry otherwise undefined */ function checkBinShouldEmit(fuzzyStack) { const entry = resolveStackEntry(fuzzyStack); // stop sampling after max sampled values -- e.g. we don't need 100 repros if (entry.traceCtr > emitOptions.binMaxSampled) { return undefined; } // check if we want to sample on this entry -- we don't need every hit on this const sampleProb = Math.pow(emitOptions.binBackoffFactor, entry.traceCtr); return (Math.random() < sampleProb) ? entry : undefined; } /* *Note that we sampled for this entry and update the info as appropriate *@sampleEntry the entry we did the sample on *@sampleName the sample we are adding */ function updateEmitInfo(sampleEntry, sampleName) { sampleEntry.traceCtr++; sampleEntry.samples.push(sampleName); } // // // Helpers for emit manager code function resolveStackEntry(fuzzyStack) { if (!callStackEmitInfoMap.has(fuzzyStack.hash)) { callStackEmitInfoMap.set(fuzzyStack.hash, []); } const stackList = callStackEmitInfoMap.get(fuzzyStack.hash); for (var i = 0; i < stackList.length; ++i) { if (eqFuzzyStacks(fuzzyStack, stackList[i].stack)) { return stackList[i]; } } stackList.push({ stack: fuzzyStack, bucketId: bucketCtr++, traceCtr: 0, samples: [] }); return stackList[stackList.length - 1]; } // ///////////////////////////// // Fuzzy stack code // Helper hashcode computation function (dbj2 variant) function djbHash(str, hash) { for (var i = 0; i < str.length; i++) { hash = (hash * 33) ^ str.charCodeAt(i); } return hash; } // helper is absolute path copied from path -- avoid neededing to require it function directIsAbsoluteW32(pth) { const len = pth.length; if (len === 0) return false; let code = pth.charCodeAt(0); if (code === 47/* / */ || code === 92/* \ */) { return true; } else if ((code >= 65/* A */ && code <= 90/* Z */) || (code >= 97/* a */ && code <= 122/* z */)) { // Possible device root if (len > 2 && pth.charCodeAt(1) === 58/* : */) { code = pth.charCodeAt(2); if (code === 47/* / */ || code === 92/* \ */) return true; } } return false; } function directIsAbsolutePosix(pth) { return pth.length > 0 && pth.charCodeAt(0) === 47/* / */; } const directIsAbsolute = (process.platform === 'win32') ? directIsAbsoluteW32 : directIsAbsolutePosix; /* * Create and return a fuzzy stack match for the current call. */ function generateFuzzyStack(eventKind) { // Create an array of the file/lines for user space code in the call stack. // eslint-disable-next-line no-restricted-syntax let errstk = new Error() .stack .split('\n') .slice(1) .map(function(frame) { return frame.substring(frame.indexOf('(') + 1, frame.lastIndexOf(')')); }) .filter(function(frame) { return directIsAbsolute(frame); }); let fname = 'empty_stack'; if (errstk.length !== 0) { const lastframe = errstk[errstk.length - 1]; fname = lastframe.substr(lastframe.lastIndexOf(path.sep) + 1) .replace('.js:', '_line-') .replace(':', '_column-'); } // Identify which frames are recursive (appear multiple times in the stack) const recFrames = new Map(); let hasRecFrames = false; for (var i = 0; i < errstk.length; ++i) { if (recFrames.has(errstk[i])) { hasRecFrames = true; recFrames.set(errstk[i], true); } else { recFrames.set(errstk[i], false); } } if (hasRecFrames) { // Compress any recursive frames let cpos = 0; let fpos = 0; while (fpos < errstk.length) { if (recFrames.get(errstk[fpos])) { const recArray = []; let spanpos = fpos; let spanend = errstk.lastIndexOf(errstk[fpos]); while (spanpos <= spanend) { if (recArray.indexOf(errstk[spanpos]) === -1) { recArray.push(errstk[spanpos]); } spanend = Math.max(spanend, errstk.lastIndexOf(errstk[spanpos])); spanpos++; } errstk[cpos] = recArray.sort(); fpos = spanend + 1; } else { if (cpos !== fpos) { errstk[cpos] = errstk[fpos]; } fpos++; } cpos++; } errstk = errstk.slice(0, cpos); } let chash = 5381; for (i = 0; i < errstk.length; ++i) { if (Array.isArray(errstk[i])) { for (var j = 0; j < errstk[i].length; ++j) { chash = djbHash(errstk[i][j], chash); } } else { chash = djbHash(errstk[i], chash); } } return { kind: eventKind, fbin: fname, hash: chash, stack: errstk }; } /* * Check if 2 fuzzy stacks are equal. */ function eqFuzzyStacks(s1, s2) { if (s1.hash !== s2.hash || s1.stack.length !== s2.stack.length) { return false; } for (var i = 0; i < s1.stack.length; ++i) { if (Array.isArray(s1.stack[i]) !== Array.isArray(s2.stack[i])) { return false; } if (Array.isArray(s1.stack[i])) { if (s1.stack[i].length !== s2.stack[i].length) { return false; } for (var j = 0; j < s1.stack[i].length; ++j) { if (s1.stack[j] !== s2.stack[j]) { return false; } } } else if (s1.stack[i] !== s2.stack[i]) { return false; } } return true; } // ///////////////////////////// // Bind handlers function onExitHandler(code) { emitTrace('emitOnExit', code); } exports.onExitHandler = onExitHandler; function onUncaughtExceptionHandler() { emitTrace('emitOnException'); } exports.onUncaughtExceptionHandler = onUncaughtExceptionHandler; function onSigIntHandler(hasUserHandler) { emitTrace('emitOnSigInt'); if (!hasUserHandler) { // Really exit without triggering any other events process.reallyExit(0); } } exports.onSigIntHandler = onSigIntHandler; reentrantDisable = false;