Skip to content
This repository has been archived by the owner on Jul 10, 2023. It is now read-only.

Commit

Permalink
Added TTD (Time Travel Debugging) (aka line-by-line tracing) support …
Browse files Browse the repository at this point in the history
…to Jest integration
  • Loading branch information
Serkan ÖZAL committed Oct 24, 2021
1 parent 6cf44da commit 029b618
Show file tree
Hide file tree
Showing 10 changed files with 381 additions and 106 deletions.
267 changes: 174 additions & 93 deletions src/opentracing/instrument/Instrumenter.ts
Original file line number Diff line number Diff line change
Expand Up @@ -20,6 +20,8 @@ const copy = require('fast-copy');
const TRACE_DEF_SEPARATOR: string = '.';
const MAX_LINES: number = 100;
const MAX_VAR_VALUE_SIZE: number = 8192; // 8KB
const MAX_ELEMENTS: number = 100;
const MAX_PROPS: number = 20;

/**
* Instruments specified/configured modules/method during load time
Expand Down Expand Up @@ -56,31 +58,7 @@ class Instrumenter {
self.setGlobalFunction();

const thundraCompile = function (content: any, filename: any) {
const relPath = path.relative(process.cwd(), filename);
let relPathWithDots = relPath.replace(/\//g, TRACE_DEF_SEPARATOR);
relPathWithDots = relPathWithDots.replace('.js', '');

const sci = self.sourceCodeInstrumenter;

if (sci.shouldTraceFile(relPathWithDots)) {
ThundraLogger.debug('<Instrumenter> Instrumenting file', filename, 'at', relPath);
let wrapped = true;
if (Module.wrapper.length === 2) {
content = Module.wrapper[0] + '\n' + content + Module.wrapper[1];
} else {
wrapped = false;
}
try {
content = sci.addTraceHooks(content, relPathWithDots, wrapped);
if (Module.wrapper.length === 2) {
content = content.substring(Module.wrapper[0].length, content.length - Module.wrapper[1].length);
}
ThundraLogger.debug('<Instrumenter> Instrumented file', filename, 'at', relPath, ':', content);
} catch (e) {
ThundraLogger.error(
'<Instrumenter> Error occurred while instrumenting file', filename, 'at', relPath, ':', e);
}
}
content = self.instrument(filename, content);

self.origCompile.call(this, content, filename);
};
Expand All @@ -91,6 +69,44 @@ class Instrumenter {
Module.prototype._compile = thundraCompile;
}

/**
* Instruments the given JS code.
*
* @param filename name of the file
* @param code the code to be instrumented
* @return {string}the instrumented code
*/
instrument(filename: string, code: string): string {
const relPath = path.relative(process.cwd(), filename);
let relPathWithDots = relPath.replace(/\//g, TRACE_DEF_SEPARATOR);
relPathWithDots = relPathWithDots.replace('.js', '');
relPathWithDots = relPathWithDots.replace('.ts', '');

const sci = this.sourceCodeInstrumenter;

if (sci.shouldTraceFile(relPathWithDots)) {
ThundraLogger.debug('<Instrumenter> Instrumenting file', filename, 'at', relPath);
let wrapped = true;
if (Module.wrapper.length === 2) {
code = Module.wrapper[0] + '\n' + code + Module.wrapper[1];
} else {
wrapped = false;
}
try {
code = sci.addTraceHooks(code, relPathWithDots, wrapped);
if (Module.wrapper.length === 2) {
code = code.substring(Module.wrapper[0].length, code.length - Module.wrapper[1].length);
}
ThundraLogger.debug('<Instrumenter> Instrumented file', filename, 'at', relPath, ':', code);
} catch (e) {
ThundraLogger.error(
'<Instrumenter> Error occurred while instrumenting file', filename, 'at', relPath, ':', e);
}
}

return code;
}

/**
* Unhooks itself from module load cycle
*/
Expand All @@ -106,73 +122,14 @@ class Instrumenter {
}
}

private checkValueSize(value: any): boolean {
try {
const valueSize = sizeof(value);
return valueSize <= MAX_VAR_VALUE_SIZE;
} catch (e) {
ThundraLogger.debug('<Instrumenter> Unable to check value size:', e);
return true;
}
}

private packValue(value: any) {
// `==` is used on purpose (instead of `===`) as it covers both undefined and null values
if (value == null) {
return null;
}
const valueType = typeof value;
if (valueType === 'function') {
return `function ${value.name}(...) { ... }`;
}
if (value instanceof Map || value instanceof Set) {
value = [...value];
}
if (!this.checkValueSize(value)) {
return '<skipped: value too big>';
}
try {
// Create deep copy to take snapshot of the value.
// So later modifications on the real value/object
// will not be reflected to the taken snapshot here.
return copy(value);
} catch (e1) {
ThundraLogger.debug('<Instrumenter> Unable to clone value:', e1);
try {
const valueJson = Utils.serializeJSON(value);
if (valueJson) {
if (valueJson.length <= MAX_VAR_VALUE_SIZE) {
return valueJson;
} else {
ThundraLogger.debug('<Instrumenter> Unable to serialize value to JSON as it is too big');
}
} else {
ThundraLogger.debug('<Instrumenter> Unable to serialize value to JSON as no JSON could produced');
}
} catch (e2) {
ThundraLogger.debug('<Instrumenter> Unable to serialize value to JSON:', e2);
}
try {
const valueStr = value.toString();
if (valueStr) {
if (valueStr.length <= MAX_VAR_VALUE_SIZE) {
return valueStr;
} else {
ThundraLogger.debug('<Instrumenter> Unable to use "toString()" of value as it is too big');
}
} else {
ThundraLogger.debug('<Instrumenter> Unable to use "toString()" of value as no string could be produced');
}
} catch (e3) {
ThundraLogger.debug('<Instrumenter> Unable to use "toString()" of value:', e3);
}
return '<unable to serialize value>';
}
}

private setGlobalFunction() {
/**
* Sets the global function
* @param glob the global
*/
setGlobalFunction(glob?: NodeJS.Global) {
const me = this;
global.__thundraTraceEntry__ = function (args: any) {
const g = glob || global;
g.__thundraTraceEntry__ = function (args: any) {
const { tracer } = ExecutionContextManager.get();
if (!tracer) {
return;
Expand Down Expand Up @@ -220,7 +177,7 @@ class Instrumenter {
}
};

global.__thundraTraceLine__ = function (args: any) {
g.__thundraTraceLine__ = function (args: any) {
let methodName = null;
try {
const entryData = args.entryData;
Expand Down Expand Up @@ -299,7 +256,7 @@ class Instrumenter {
}
};

global.__thundraTraceExit__ = function (args: any) {
g.__thundraTraceExit__ = function (args: any) {
let methodName = null;
const { tracer } = ExecutionContextManager.get();
if (!tracer) {
Expand Down Expand Up @@ -344,6 +301,130 @@ class Instrumenter {
};
}

private checkValueSize(value: any): boolean {
try {
const valueSize = sizeof(value);
return valueSize <= MAX_VAR_VALUE_SIZE;
} catch (e) {
ThundraLogger.debug('<Instrumenter> Unable to check value size:', e);
return true;
}
}

private packValue(value: any) {
// `==` is used on purpose (instead of `===`) as it covers both undefined and null values
if (value == null) {
return null;
}
const valueType = typeof value;
if (valueType === 'function') {
return `function ${value.name}(...) { ... }`;
}
if (value instanceof Map || value instanceof Set) {
value = [...value];
}
if (!this.checkValueSize(value)) {
return this.summarizeValue(value);
}
try {
// Create deep copy to take snapshot of the value.
// So later modifications on the real value/object
// will not be reflected to the taken snapshot here.
return copy(value);
} catch (e1) {
ThundraLogger.debug('<Instrumenter> Unable to clone value:', e1);
try {
const valueJson = Utils.serializeJSON(value);
if (valueJson) {
if (valueJson.length <= MAX_VAR_VALUE_SIZE) {
return valueJson;
} else {
ThundraLogger.debug('<Instrumenter> Unable to serialize value to JSON as it is too big');
}
} else {
ThundraLogger.debug('<Instrumenter> Unable to serialize value to JSON as no JSON could produced');
}
} catch (e2) {
ThundraLogger.debug('<Instrumenter> Unable to serialize value to JSON:', e2);
}
try {
const valueStr = value.toString();
if (valueStr) {
if (valueStr.length <= MAX_VAR_VALUE_SIZE) {
return valueStr;
} else {
ThundraLogger.debug('<Instrumenter> Unable to use "toString()" of value as it is too big');
}
} else {
ThundraLogger.debug('<Instrumenter> Unable to use "toString()" of value as no string could be produced');
}
} catch (e3) {
ThundraLogger.debug('<Instrumenter> Unable to use "toString()" of value:', e3);
}
return '<unable to serialize value>';
}
}

private summarizeValue(value: any): any {
if (Array.isArray(value)) {
return this.summarizeArray(value);
} else {
return this.summarizeObject(value);
}
}

private summarizeArray(array: any[]): any[] {
const summary: any = [];
const elementCount = Math.min(array.length, MAX_ELEMENTS);
const maxElementSize = 2 * (MAX_VAR_VALUE_SIZE / elementCount);
let currentSize: number = 0;
for (let i = 0; i < elementCount; i++) {
const element = array[i];
const elementSize = sizeof(element);
// Check whether
// - the element is small enough
// - the new size will not exceed the max size with the new element
if ((elementSize <= maxElementSize) && (currentSize + elementSize <= MAX_VAR_VALUE_SIZE)) {
summary[i] = copy(element);
currentSize += elementSize;
} else {
summary[i] = '<skipped: element too big>';
}
}
return summary;
}

private summarizeObject(obj: any): any {
// First, sort object properties by their sizes
obj = Object.entries(obj).
sort((kv1: any[], kv2: any[]) => {
const size1 = sizeof(kv1[1]);
const size2 = sizeof(kv2[1]);
return size1 - size2;
}).
reduce((sorted: any, kv: any[]) => {
sorted[kv[0]] = kv[1];
return sorted;
}, {});

// Then shallow copy properties by starting from the smallest one until it reaches to the max limit
const summary: any = {};
const keys = Object.keys(obj);
let currentSize: number = 0;
for (let i = 0; i < keys.length && i < MAX_PROPS; i++) {
const key = keys[i];
const prop = obj[key];
const propSize = sizeof(prop);
// Check whether the new size will exceed the max size with the new prop
if (currentSize + propSize > MAX_VAR_VALUE_SIZE) {
break;
}
summary[key] = copy(prop);
currentSize += propSize;
}
return summary;
}

}

export default Instrumenter;
12 changes: 11 additions & 1 deletion src/plugins/Invocation.ts
Original file line number Diff line number Diff line change
Expand Up @@ -3,13 +3,16 @@ import InvocationConfig from './config/InvocationConfig';
import PluginContext from './PluginContext';
import ExecutionContext from '../context/ExecutionContext';
import ThundraLogger from '../ThundraLogger';
import Plugin from './Plugin';

const get = require('lodash.get');

/**
* The invocation plugin
*/
export default class Invocation {
export default class Invocation implements Plugin {

public static readonly NAME: string = 'Invocation';

pluginOrder: number = 2;
pluginContext: PluginContext;
Expand All @@ -27,6 +30,13 @@ export default class Invocation {
this.options = options;
}

/**
* @inheritDoc
*/
getName(): string {
return Invocation.NAME;
}

/**
* Sets the the {@link PluginContext}
* @param {PluginContext} pluginContext the {@link PluginContext}
Expand Down
12 changes: 11 additions & 1 deletion src/plugins/Log.ts
Original file line number Diff line number Diff line change
Expand Up @@ -13,13 +13,16 @@ import ConfigNames from '../config/ConfigNames';
import InvocationTraceSupport from './support/InvocationTraceSupport';
import LogManager from './LogManager';
import ExecutionContext from '../context/ExecutionContext';
import Plugin from './Plugin';

const get = require('lodash.get');

/**
* The log plugin for log support
*/
export default class Log {
export default class Log implements Plugin {

public static readonly NAME: string = 'Log';

pluginOrder: number = 4;
pluginContext: PluginContext;
Expand Down Expand Up @@ -53,6 +56,13 @@ export default class Log {
}
}

/**
* @inheritDoc
*/
getName(): string {
return Log.NAME;
}

/**
* Sets the the {@link PluginContext}
* @param {PluginContext} pluginContext the {@link PluginContext}
Expand Down

0 comments on commit 029b618

Please sign in to comment.