Skip to content

Commit 4844dc3

Browse files
V3RONV3RON
authored
refactor: improve logging capabilities (#87)
Improves Harness debug logging so it is much easier to follow what the runtime is doing during startup, retries, readiness checks, and crash handling. Internal logs now use a simpler plain-console format with timestamps and clear scope tags, while the existing user-facing Jest output stays unchanged.
1 parent bf75f8e commit 4844dc3

File tree

16 files changed

+447
-183
lines changed

16 files changed

+447
-183
lines changed

‎actions/shared/index.cjs‎

Lines changed: 91 additions & 58 deletions
Original file line numberDiff line numberDiff line change
@@ -158,20 +158,6 @@ var require_src = __commonJS({
158158
}
159159
});
160160

161-
// ../../node_modules/is-unicode-supported/index.js
162-
var require_is_unicode_supported = __commonJS({
163-
"../../node_modules/is-unicode-supported/index.js"(exports2, module2) {
164-
"use strict";
165-
module2.exports = () => {
166-
if (process.platform !== "win32") {
167-
return true;
168-
}
169-
return Boolean(process.env.CI) || Boolean(process.env.WT_SESSION) || // Windows Terminal
170-
process.env.TERM_PROGRAM === "vscode" || process.env.TERM === "xterm-256color" || process.env.TERM === "alacritty";
171-
};
172-
}
173-
});
174-
175161
// ../../node_modules/zod/dist/esm/v3/external.js
176162
var external_exports = {};
177163
__export(external_exports, {
@@ -4208,45 +4194,56 @@ var coerce = {
42084194
};
42094195
var NEVER = INVALID;
42104196

4211-
// ../plugins/dist/utils.js
4212-
var isHookTree = (value) => {
4213-
if (value == null || typeof value !== "object" || Array.isArray(value)) {
4214-
return false;
4215-
}
4216-
for (const child of Object.values(value)) {
4217-
if (child === void 0) {
4218-
continue;
4219-
}
4220-
if (typeof child === "function") {
4221-
continue;
4222-
}
4223-
if (child == null || typeof child !== "object" || Array.isArray(child) || !isHookTree(child)) {
4224-
return false;
4225-
}
4226-
}
4227-
return true;
4197+
// ../tools/dist/logger.js
4198+
var import_node_util = __toESM(require("util"), 1);
4199+
var verbose = !!process.env.HARNESS_DEBUG;
4200+
var BASE_TAG = "[harness]";
4201+
var getTimestamp = () => (/* @__PURE__ */ new Date()).toISOString();
4202+
var normalizeScope = (scope) => scope.trim().replace(/^\[+|\]+$/g, "").replace(/\]\[/g, "][");
4203+
var formatPrefix = (scopes) => {
4204+
const suffix = scopes.map((scope) => `[${normalizeScope(scope)}]`).join("");
4205+
return `${BASE_TAG}${suffix}`;
42284206
};
4229-
4230-
// ../plugins/dist/plugin.js
4231-
var isHarnessPlugin = (value) => {
4232-
if (value == null || typeof value !== "object" || Array.isArray(value)) {
4233-
return false;
4234-
}
4235-
const candidate = value;
4236-
if (typeof candidate.name !== "string" || candidate.name.length === 0) {
4237-
return false;
4238-
}
4239-
if (candidate.createState != null && typeof candidate.createState !== "function") {
4240-
return false;
4241-
}
4242-
if (candidate.hooks != null && !isHookTree(candidate.hooks)) {
4243-
return false;
4244-
}
4245-
return true;
4207+
var mapLines = (text, prefix) => text.split("\n").map((line) => `${prefix} ${line}`).join("\n");
4208+
var writeLog = (level, scopes, messages) => {
4209+
const method = level === "warn" ? console.warn : level === "error" ? console.error : level === "debug" ? console.debug : console.info;
4210+
const output = import_node_util.default.format(...messages);
4211+
const prefix = `${getTimestamp()} ${formatPrefix(scopes)}`;
4212+
method(mapLines(output, prefix));
42464213
};
4247-
4248-
// ../tools/dist/logger.js
4249-
var import_node_util2 = __toESM(require("util"), 1);
4214+
var setVerbose = (level) => {
4215+
verbose = level;
4216+
};
4217+
var isVerbose = () => {
4218+
return verbose;
4219+
};
4220+
var createScopedLogger = (scopes = []) => ({
4221+
debug: (...messages) => {
4222+
if (!verbose) {
4223+
return;
4224+
}
4225+
writeLog("debug", scopes, messages);
4226+
},
4227+
info: (...messages) => {
4228+
writeLog("info", scopes, messages);
4229+
},
4230+
warn: (...messages) => {
4231+
writeLog("warn", scopes, messages);
4232+
},
4233+
error: (...messages) => {
4234+
writeLog("error", scopes, messages);
4235+
},
4236+
log: (...messages) => {
4237+
writeLog("log", scopes, messages);
4238+
},
4239+
success: (...messages) => {
4240+
writeLog("success", scopes, messages);
4241+
},
4242+
child: (scope) => createScopedLogger([...scopes, scope]),
4243+
setVerbose,
4244+
isVerbose
4245+
});
4246+
var logger = createScopedLogger();
42504247

42514248
// ../../node_modules/@clack/core/dist/index.mjs
42524249
var import_node_process = require("process");
@@ -4271,7 +4268,7 @@ var import_node_process2 = __toESM(require("process"), 1);
42714268
var import_node_fs = require("fs");
42724269
var import_node_path = require("path");
42734270
var import_sisteransi2 = __toESM(require_src(), 1);
4274-
var import_node_util = require("util");
4271+
var import_node_util2 = require("util");
42754272
function ht() {
42764273
return import_node_process2.default.platform !== "win32" ? import_node_process2.default.env.TERM !== "linux" : !!import_node_process2.default.env.CI || !!import_node_process2.default.env.WT_SESSION || !!import_node_process2.default.env.TERMINUS_SUBLIME || import_node_process2.default.env.ConEmuTask === "{cmd::Cmder}" || import_node_process2.default.env.TERM_PROGRAM === "Terminus-Sublime" || import_node_process2.default.env.TERM_PROGRAM === "vscode" || import_node_process2.default.env.TERM === "xterm-256color" || import_node_process2.default.env.TERM === "alacritty" || import_node_process2.default.env.TERMINAL_EMULATOR === "JetBrains-JediTerm";
42774274
}
@@ -4313,12 +4310,8 @@ var Ut = import_picocolors.default.magenta;
43134310
var Ye = { light: w("\u2500", "-"), heavy: w("\u2501", "="), block: w("\u2588", "#") };
43144311
var ze = `${import_picocolors.default.gray(h)} `;
43154312

4316-
// ../tools/dist/logger.js
4317-
var import_is_unicode_supported = __toESM(require_is_unicode_supported(), 1);
4318-
var unicode = (0, import_is_unicode_supported.default)();
4319-
var unicodeWithFallback = (c, fallback) => unicode ? c : fallback;
4320-
var SYMBOL_DEBUG = unicodeWithFallback("\u25CF", "\u2022");
4321-
var verbose = !!process.env.HARNESS_DEBUG;
4313+
// ../tools/dist/spawn.js
4314+
var spawnLogger = logger.child("spawn");
43224315

43234316
// ../tools/dist/react-native.js
43244317
var import_node_module = require("module");
@@ -4338,6 +4331,46 @@ var import_node_fs4 = __toESM(require("fs"), 1);
43384331
var import_node_path4 = __toESM(require("path"), 1);
43394332
var DEFAULT_ARTIFACT_ROOT = import_node_path4.default.join(process.cwd(), ".harness", "crash-reports");
43404333

4334+
// ../plugins/dist/utils.js
4335+
var isHookTree = (value) => {
4336+
if (value == null || typeof value !== "object" || Array.isArray(value)) {
4337+
return false;
4338+
}
4339+
for (const child of Object.values(value)) {
4340+
if (child === void 0) {
4341+
continue;
4342+
}
4343+
if (typeof child === "function") {
4344+
continue;
4345+
}
4346+
if (child == null || typeof child !== "object" || Array.isArray(child) || !isHookTree(child)) {
4347+
return false;
4348+
}
4349+
}
4350+
return true;
4351+
};
4352+
4353+
// ../plugins/dist/plugin.js
4354+
var isHarnessPlugin = (value) => {
4355+
if (value == null || typeof value !== "object" || Array.isArray(value)) {
4356+
return false;
4357+
}
4358+
const candidate = value;
4359+
if (typeof candidate.name !== "string" || candidate.name.length === 0) {
4360+
return false;
4361+
}
4362+
if (candidate.createState != null && typeof candidate.createState !== "function") {
4363+
return false;
4364+
}
4365+
if (candidate.hooks != null && !isHookTree(candidate.hooks)) {
4366+
return false;
4367+
}
4368+
return true;
4369+
};
4370+
4371+
// ../plugins/dist/manager.js
4372+
var pluginsLogger = logger.child("plugins");
4373+
43414374
// ../config/dist/types.js
43424375
var DEFAULT_METRO_PORT = 8081;
43434376
var RunnerSchema = external_exports.object({

‎packages/bridge/src/server.ts‎

Lines changed: 8 additions & 4 deletions
Original file line numberDiff line numberDiff line change
@@ -22,6 +22,7 @@ import { DeviceNotRespondingError } from './errors.js';
2222
import { matchImageSnapshot } from './image-snapshot.js';
2323

2424
export { DeviceNotRespondingError } from './errors.js';
25+
const bridgeLogger = logger.child('bridge');
2526

2627
export type BridgeServerOptions = {
2728
port: number;
@@ -63,6 +64,7 @@ export const getBridgeServer = async ({
6364
resolve(server);
6465
});
6566
});
67+
bridgeLogger.debug('bridge server listening on port %d', port);
6668
const emitter = new EventEmitter();
6769
const clients = new Set<WebSocket>();
6870
const binaryStore = new BinaryStore();
@@ -121,7 +123,8 @@ export const getBridgeServer = async ({
121123
{
122124
timeout,
123125
onFunctionError: (error, functionName, args) => {
124-
console.error('Function error', error, functionName, args);
126+
bridgeLogger.error('rpc function failed: %s args=%o', functionName, args);
127+
bridgeLogger.error(error);
125128
throw error;
126129
},
127130
onTimeoutError(functionName, args) {
@@ -131,9 +134,9 @@ export const getBridgeServer = async ({
131134
);
132135

133136
wss.on('connection', (ws: WebSocket) => {
134-
logger.debug('Client connected to the bridge');
137+
bridgeLogger.debug('client connected');
135138
ws.on('close', () => {
136-
logger.debug('Client disconnected from the bridge');
139+
bridgeLogger.debug('client disconnected');
137140

138141
// TODO: Remove channel when connection is closed.
139142
clients.delete(ws);
@@ -154,7 +157,7 @@ export const getBridgeServer = async ({
154157
binaryStore.add(transferId, data);
155158
return;
156159
} catch (error) {
157-
logger.warn('Failed to parse binary frame', error);
160+
bridgeLogger.warn('failed to parse binary frame', error);
158161
}
159162
}
160163
const message = event.toString();
@@ -169,6 +172,7 @@ export const getBridgeServer = async ({
169172
});
170173

171174
const dispose = () => {
175+
bridgeLogger.debug('disposing bridge server');
172176
for (const client of wss.clients) {
173177
client.terminate();
174178
}

‎packages/bundler-metro/src/factory.ts‎

Lines changed: 8 additions & 2 deletions
Original file line numberDiff line numberDiff line change
@@ -16,6 +16,7 @@ import { getBundleRequestObserverMiddleware } from './middlewares/bundle-request
1616
import { getStatusMiddleware } from './middlewares/status-middleware.js';
1717
import { prewarmMetroBundle } from './prewarm.js';
1818
import { withRnHarness } from './withRnHarness.js';
19+
const metroLogger = logger.child('metro');
1920

2021
const METRO_STATUS_POLL_INTERVAL_MS = 500;
2122
const METRO_STATUS_REQUEST_TIMEOUT_MS = 1000;
@@ -91,6 +92,11 @@ export const getMetroInstance = async (
9192
): Promise<MetroInstance> => {
9293
const { projectRoot, harnessConfig } = options;
9394
const metroPort = harnessConfig.metroPort;
95+
metroLogger.debug(
96+
'creating Metro instance for %s on port %d',
97+
projectRoot,
98+
metroPort
99+
);
94100
const isMetroPortAvailable = await isPortAvailable(metroPort);
95101

96102
if (!isMetroPortAvailable) {
@@ -119,7 +125,7 @@ export const getMetroInstance = async (
119125
const ready = waitForBundler(reporter, abortSignal);
120126
const metroBindHost = harnessConfig.host?.trim();
121127
if (metroBindHost) {
122-
logger.debug(`Binding Metro server to host ${metroBindHost}`);
128+
metroLogger.debug('binding Metro server to host %s', metroBindHost);
123129
}
124130

125131
const maybeServer = await Metro.runServer(config, {
@@ -138,7 +144,7 @@ export const getMetroInstance = async (
138144

139145
await ready;
140146

141-
logger.debug('Metro server is running');
147+
metroLogger.debug('Metro server is running');
142148

143149
let prewarmResult: Promise<boolean> | null = null;
144150

‎packages/jest/src/crash-supervisor.ts‎

Lines changed: 13 additions & 6 deletions
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,8 @@ import {
1212
} from './errors.js';
1313
import { logger } from '@react-native-harness/tools';
1414

15+
const crashLogger = logger.child('crash');
16+
1517
export type CrashSupervisorState =
1618
| 'idle'
1719
| 'launching'
@@ -113,15 +115,20 @@ export const createCrashSupervisor = ({
113115
}
114116

115117
if (!activeTestFilePath) {
116-
logger.debug(`Ignoring crash signal without active test: ${reason}`);
118+
crashLogger.debug('ignoring crash signal without active test: %s', reason);
117119
return;
118120
}
119121

120122
isResolvingCrash = true;
121-
logger.debug(`Native crash detected during ${activeTestFilePath} (state: ${state}, reason: ${reason || '(none)'})`);
123+
crashLogger.debug(
124+
'native crash detected during %s (state=%s reason=%s)',
125+
activeTestFilePath,
126+
state,
127+
reason || '(none)'
128+
);
122129

123130
for (const line of details?.rawLines ?? []) {
124-
logger.debug(line);
131+
crashLogger.debug('%s', line);
125132
}
126133

127134
const phase = getCrashPhase(state);
@@ -136,7 +143,7 @@ export const createCrashSupervisor = ({
136143
});
137144

138145
const mergedDetails = mergeCrashDetails(phase, details, enrichedDetails, reason);
139-
logger.debug('Crash details:', {
146+
crashLogger.debug('crash details: %o', {
140147
phase: mergedDetails.phase,
141148
source: mergedDetails.source,
142149
summary: mergedDetails.summary,
@@ -160,10 +167,10 @@ export const createCrashSupervisor = ({
160167
const isRunning = await platformRunner.isAppRunning();
161168

162169
if (!isRunning) {
163-
handleCrash(reason, details);
170+
void handleCrash(reason, details);
164171
}
165172
} catch (error) {
166-
logger.debug('Crash confirmation failed', error);
173+
crashLogger.debug('crash confirmation failed', error);
167174
}
168175
};
169176

0 commit comments

Comments
 (0)