debug.ts 6.1 KB

123456789101112131415161718192021222324252627282930313233343536373839404142434445464748495051525354555657585960616263646566676869707172737475767778798081828384858687888990919293949596979899100101102103104105106107108109110111112113114115116117118119120121122123124125126127128129130131132133134135136137138139140141142143144145146147148149150151152153154155156157158159160161162163164165166167168169170171172173174175176177178179180181182183184185186187188189190191192193194195196197198199200201202203204205206207208209210211212213214215216217218219220
  1. const lessPrecise = (num: number, precision = 5) =>
  2. parseFloat(num.toPrecision(precision));
  3. const getAvgFrameTime = (times: number[]) =>
  4. lessPrecise(times.reduce((a, b) => a + b) / times.length);
  5. export class Debug {
  6. public static DEBUG_LOG_TIMES = true;
  7. private static TIMES_AGGR: Record<string, { t: number; times: number[] }> =
  8. {};
  9. private static TIMES_AVG: Record<
  10. string,
  11. { t: number; times: number[]; avg: number | null }
  12. > = {};
  13. private static LAST_DEBUG_LOG_CALL = 0;
  14. private static DEBUG_LOG_INTERVAL_ID: null | number = null;
  15. private static LAST_FRAME_TIMESTAMP = 0;
  16. private static FRAME_COUNT = 0;
  17. private static ANIMATION_FRAME_ID: null | number = null;
  18. private static scheduleAnimationFrame = () => {
  19. if (Debug.DEBUG_LOG_INTERVAL_ID !== null) {
  20. Debug.ANIMATION_FRAME_ID = requestAnimationFrame((timestamp) => {
  21. if (Debug.LAST_FRAME_TIMESTAMP !== timestamp) {
  22. Debug.LAST_FRAME_TIMESTAMP = timestamp;
  23. Debug.FRAME_COUNT++;
  24. }
  25. if (Debug.DEBUG_LOG_INTERVAL_ID !== null) {
  26. Debug.scheduleAnimationFrame();
  27. }
  28. });
  29. }
  30. };
  31. private static setupInterval = () => {
  32. if (Debug.DEBUG_LOG_INTERVAL_ID === null) {
  33. console.info("%c(starting perf recording)", "color: lime");
  34. Debug.DEBUG_LOG_INTERVAL_ID = window.setInterval(Debug.debugLogger, 1000);
  35. Debug.scheduleAnimationFrame();
  36. }
  37. Debug.LAST_DEBUG_LOG_CALL = Date.now();
  38. };
  39. private static debugLogger = () => {
  40. if (Debug.DEBUG_LOG_TIMES) {
  41. for (const [name, { t, times }] of Object.entries(Debug.TIMES_AGGR)) {
  42. if (times.length) {
  43. console.info(
  44. name,
  45. lessPrecise(times.reduce((a, b) => a + b)),
  46. times.sort((a, b) => a - b).map((x) => lessPrecise(x)),
  47. );
  48. Debug.TIMES_AGGR[name] = { t, times: [] };
  49. }
  50. }
  51. for (const [name, { t, times, avg }] of Object.entries(Debug.TIMES_AVG)) {
  52. if (times.length) {
  53. // const avgFrameTime = getAvgFrameTime(times);
  54. const totalTime = times.reduce((a, b) => a + b);
  55. const avgFrameTime = lessPrecise(totalTime / Debug.FRAME_COUNT);
  56. console.info(
  57. name,
  58. `- ${times.length} calls - ${avgFrameTime}ms/frame across ${
  59. Debug.FRAME_COUNT
  60. } frames (${lessPrecise(
  61. (avgFrameTime / 16.67) * 100,
  62. 1,
  63. )}% of frame budget)`,
  64. );
  65. Debug.TIMES_AVG[name] = {
  66. t,
  67. times: [],
  68. avg:
  69. avg != null ? getAvgFrameTime([avg, avgFrameTime]) : avgFrameTime,
  70. };
  71. }
  72. }
  73. }
  74. Debug.FRAME_COUNT = 0;
  75. // Check for stop condition after logging
  76. if (
  77. Date.now() - Debug.LAST_DEBUG_LOG_CALL > 600 &&
  78. Debug.DEBUG_LOG_INTERVAL_ID !== null
  79. ) {
  80. console.info("%c(stopping perf recording)", "color: red");
  81. window.clearInterval(Debug.DEBUG_LOG_INTERVAL_ID);
  82. window.cancelAnimationFrame(Debug.ANIMATION_FRAME_ID!);
  83. Debug.ANIMATION_FRAME_ID = null;
  84. Debug.FRAME_COUNT = 0;
  85. Debug.LAST_FRAME_TIMESTAMP = 0;
  86. Debug.DEBUG_LOG_INTERVAL_ID = null;
  87. Debug.TIMES_AGGR = {};
  88. Debug.TIMES_AVG = {};
  89. }
  90. };
  91. public static logTime = (time?: number, name = "default") => {
  92. Debug.setupInterval();
  93. const now = performance.now();
  94. const { t, times } = (Debug.TIMES_AGGR[name] = Debug.TIMES_AGGR[name] || {
  95. t: 0,
  96. times: [],
  97. });
  98. if (t) {
  99. times.push(time != null ? time : now - t);
  100. }
  101. Debug.TIMES_AGGR[name].t = now;
  102. };
  103. public static logTimeAverage = (time?: number, name = "default") => {
  104. Debug.setupInterval();
  105. const now = performance.now();
  106. const { t, times } = (Debug.TIMES_AVG[name] = Debug.TIMES_AVG[name] || {
  107. t: 0,
  108. times: [],
  109. });
  110. if (t) {
  111. times.push(time != null ? time : now - t);
  112. }
  113. Debug.TIMES_AVG[name].t = now;
  114. };
  115. private static logWrapper =
  116. (type: "logTime" | "logTimeAverage") =>
  117. <T extends any[], R>(fn: (...args: T) => R, name = "default") => {
  118. return (...args: T) => {
  119. const t0 = performance.now();
  120. const ret = fn(...args);
  121. Debug[type](performance.now() - t0, name);
  122. return ret;
  123. };
  124. };
  125. public static logTimeWrap = Debug.logWrapper("logTime");
  126. public static logTimeAverageWrap = Debug.logWrapper("logTimeAverage");
  127. public static perfWrap = <T extends any[], R>(
  128. fn: (...args: T) => R,
  129. name = "default",
  130. ) => {
  131. return (...args: T) => {
  132. // eslint-disable-next-line no-console
  133. console.time(name);
  134. const ret = fn(...args);
  135. // eslint-disable-next-line no-console
  136. console.timeEnd(name);
  137. return ret;
  138. };
  139. };
  140. private static CHANGED_CACHE: Record<string, Record<string, unknown>> = {};
  141. public static logChanged(name: string, obj: Record<string, unknown>) {
  142. const prev = Debug.CHANGED_CACHE[name];
  143. Debug.CHANGED_CACHE[name] = obj;
  144. if (!prev) {
  145. return;
  146. }
  147. const allKeys = new Set([...Object.keys(prev), ...Object.keys(obj)]);
  148. const changed: Record<string, { prev: unknown; next: unknown }> = {};
  149. for (const key of allKeys) {
  150. const prevVal = prev[key];
  151. const nextVal = obj[key];
  152. if (!deepEqual(prevVal, nextVal)) {
  153. changed[key] = { prev: prevVal, next: nextVal };
  154. }
  155. }
  156. if (Object.keys(changed).length > 0) {
  157. console.info(`[${name}] changed:`, changed);
  158. }
  159. }
  160. }
  161. function deepEqual(a: unknown, b: unknown): boolean {
  162. if (Object.is(a, b)) {
  163. return true;
  164. }
  165. if (
  166. a === null ||
  167. b === null ||
  168. typeof a !== "object" ||
  169. typeof b !== "object"
  170. ) {
  171. return false;
  172. }
  173. if (Array.isArray(a) !== Array.isArray(b)) {
  174. return false;
  175. }
  176. const keysA = Object.keys(a as Record<string, unknown>);
  177. const keysB = Object.keys(b as Record<string, unknown>);
  178. if (keysA.length !== keysB.length) {
  179. return false;
  180. }
  181. for (const key of keysA) {
  182. if (
  183. !deepEqual(
  184. (a as Record<string, unknown>)[key],
  185. (b as Record<string, unknown>)[key],
  186. )
  187. ) {
  188. return false;
  189. }
  190. }
  191. return true;
  192. }