log time since last communication (#50436)

Summary:
Pull Request resolved: https://github.com/facebook/react-native/pull/50436

Changelog: [Internal]

`is_idle` was a confusing concept that I didn't find useful when researching why disconnections happen. Instead, I'd like to know when the last communication with inspector proxy took place.

Reviewed By: hoxyq

Differential Revision: D72251072

fbshipit-source-id: 10f83bde6c8f3ed4b661bcfbef57f86f34039e5d
This commit is contained in:
Vitali Zaidman
2025-04-03 05:47:05 -07:00
committed by Facebook GitHub Bot
parent ca7baa1d17
commit adff5fcd35
2 changed files with 17 additions and 32 deletions
@@ -38,8 +38,6 @@ const PAGES_LIST_JSON_URL = '/json';
const PAGES_LIST_JSON_URL_2 = '/json/list';
const PAGES_LIST_JSON_VERSION_URL = '/json/version';
const PROXY_IDLE_TIMEOUT_MS = 10000;
const HEARTBEAT_TIME_BETWEEN_PINGS_MS = 5000;
const HEARTBEAT_TIMEOUT_MS = 60000;
const MIN_PING_TO_REPORT = 500;
@@ -89,7 +87,7 @@ export default class InspectorProxy implements InspectorProxyQueries {
#logger: ?Logger;
#lastMessageTimestamp: number = 0;
#lastMessageTimestamp: number | null = null;
#eventLoopPerfTracker: EventLoopPerfTracker;
@@ -283,10 +281,9 @@ export default class InspectorProxy implements InspectorProxyQueries {
response.end(data);
}
/* returns true if proxy didn't receive any messages from
* either the device or debugger for PROXY_IDLE_TIMEOUT_MS */
#isIdle(): boolean {
return Date.now() - this.#lastMessageTimestamp > PROXY_IDLE_TIMEOUT_MS;
#getTimeSinceLastCommunication(): number | null {
const timestamp = this.#lastMessageTimestamp;
return timestamp == null ? null : Date.now() - timestamp;
}
#onMessageFromDeviceOrDebugger(
@@ -390,20 +387,17 @@ export default class InspectorProxy implements InspectorProxyQueries {
minHighPingToReport: MIN_PING_TO_REPORT,
timeoutMs: HEARTBEAT_TIMEOUT_MS,
onHighPing: roundtripDuration => {
const isIdle = this.#isIdle();
debug(
"[high ping] [ Device ] %sms for app='%s' on device='%s' with idle='%s'",
"[high ping] [ Device ] %sms for app='%s' on device='%s'",
String(roundtripDuration).padStart(5),
debuggerSessionIDs.appId,
debuggerSessionIDs.deviceName,
isIdle ? 'true' : 'false',
);
this.#eventReporter?.logEvent({
type: 'device_high_ping',
duration: roundtripDuration,
isIdle,
timeSinceLastCommunication: this.#getTimeSinceLastCommunication(),
connectionUptime: Date.now() - wssTimestamp,
...debuggerSessionIDs,
});
@@ -416,20 +410,17 @@ export default class InspectorProxy implements InspectorProxyQueries {
// inform any clients.
socket.terminate();
const isIdle = this.#isIdle();
this.#logger?.error(
"[timeout] connection terminated with Device for app='%s' on device='%s' with idle='%s' after not responding for %s seconds.",
"[timeout] connection terminated with Device for app='%s' on device='%s' after not responding for %s seconds.",
debuggerSessionIDs.appId ?? 'unknown',
debuggerSessionIDs.deviceName ?? 'unknown',
isIdle ? 'true' : 'false',
String(roundtripDuration / 1000),
);
this.#eventReporter?.logEvent({
type: 'device_timeout',
duration: roundtripDuration,
isIdle,
timeSinceLastCommunication: this.#getTimeSinceLastCommunication(),
connectionUptime: Date.now() - wssTimestamp,
...debuggerSessionIDs,
});
@@ -459,7 +450,7 @@ export default class InspectorProxy implements InspectorProxyQueries {
type: 'device_connection_closed',
code,
reason,
isIdle: this.#isIdle(),
timeSinceLastCommunication: this.#getTimeSinceLastCommunication(),
connectionUptime: Date.now() - wssTimestamp,
...debuggerSessionIDs,
});
@@ -537,20 +528,17 @@ export default class InspectorProxy implements InspectorProxyQueries {
minHighPingToReport: MIN_PING_TO_REPORT,
timeoutMs: HEARTBEAT_TIMEOUT_MS,
onHighPing: roundtripDuration => {
const isIdle = this.#isIdle();
debug(
"[high ping] [DevTools] %sms for app='%s' on device='%s' with idle='%s'",
"[high ping] [DevTools] %sms for app='%s' on device='%s'",
String(roundtripDuration).padStart(5),
debuggerSessionIDs.appId,
debuggerSessionIDs.deviceName,
isIdle ? 'true' : 'false',
);
this.#eventReporter?.logEvent({
type: 'debugger_high_ping',
duration: roundtripDuration,
isIdle,
timeSinceLastCommunication: this.#getTimeSinceLastCommunication(),
connectionUptime: Date.now() - wssTimestamp,
...debuggerSessionIDs,
});
@@ -563,20 +551,17 @@ export default class InspectorProxy implements InspectorProxyQueries {
// inform any clients.
socket.terminate();
const isIdle = this.#isIdle();
this.#logger?.error(
"[timeout] connection terminated with DevTools for app='%s' on device='%s' with idle='%s' after not responding for %s seconds.",
"[timeout] connection terminated with DevTools for app='%s' on device='%s' after not responding for %s seconds.",
debuggerSessionIDs.appId ?? 'unknown',
debuggerSessionIDs.deviceName ?? 'unknown',
isIdle ? 'true' : 'false',
String(roundtripDuration / 1000),
);
this.#eventReporter?.logEvent({
type: 'debugger_timeout',
duration: roundtripDuration,
isIdle,
timeSinceLastCommunication: this.#getTimeSinceLastCommunication(),
connectionUptime: Date.now() - wssTimestamp,
...debuggerSessionIDs,
});
@@ -611,7 +596,7 @@ export default class InspectorProxy implements InspectorProxyQueries {
type: 'debugger_connection_closed',
code,
reason,
isIdle: this.#isIdle(),
timeSinceLastCommunication: this.#getTimeSinceLastCommunication(),
connectionUptime: Date.now() - wssTimestamp,
...debuggerSessionIDs,
});
@@ -106,14 +106,14 @@ export type ReportableEvent =
| {
type: 'debugger_high_ping' | 'device_high_ping',
duration: number,
isIdle: boolean,
timeSinceLastCommunication: number | null,
...ConnectionUptime,
...DebuggerSessionIDs,
}
| {
type: 'debugger_timeout' | 'device_timeout',
duration: number,
isIdle: boolean,
timeSinceLastCommunication: number | null,
...ConnectionUptime,
...DebuggerSessionIDs,
}
@@ -121,7 +121,7 @@ export type ReportableEvent =
type: 'debugger_connection_closed' | 'device_connection_closed',
code: number,
reason: string,
isIdle: boolean,
timeSinceLastCommunication: number | null,
...ConnectionUptime,
...DebuggerSessionIDs,
}