Skip to content

Commit 89dcded

Browse files
author
Anna Gringauze
authored
Added more analytics (#1420)
* Added more analytics Helps: #1419 * Update HTTP_REQUEST_EXCEPTION event to match other events * Addressed CR comments, added event on fullReload as well
1 parent 0f9610b commit 89dcded

File tree

9 files changed

+522
-375
lines changed

9 files changed

+522
-375
lines changed

dwds/CHANGELOG.md

Lines changed: 5 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -6,7 +6,11 @@
66
- Use default constant port for debug service.
77
- If we fail binding to the port, fall back to previous strategy
88
of finding unbound ports.
9-
- Add metrics measuring DevTools Initial Page Load time.
9+
- Add metrics measuring
10+
- DevTools Initial Page Load time
11+
- Various VM API
12+
- Hot restart
13+
- Http request handling exceptions
1014
- Add `ext.dwds.sendEvent` service extension to dwds so other tools
1115
can send events to the debugger.
1216
Event format:

dwds/lib/dwds.dart

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -86,7 +86,9 @@ class Dwds {
8686

8787
Future<DebugConnection> debugConnection(AppConnection appConnection) async {
8888
if (!_enableDebugging) throw StateError('Debugging is not enabled.');
89-
var appDebugServices = await _devHandler.loadAppServices(appConnection);
89+
final dwdsStats = DwdsStats(DateTime.now());
90+
var appDebugServices =
91+
await _devHandler.loadAppServices(appConnection, dwdsStats);
9092
await appDebugServices.chromeProxyService.isInitialized;
9193
return DebugConnection(appDebugServices);
9294
}

dwds/lib/src/dwds_vm_client.dart

Lines changed: 79 additions & 63 deletions
Original file line numberDiff line numberDiff line change
@@ -80,71 +80,19 @@ class DwdsVmClient {
8080
}
8181
};
8282
});
83-
await client.registerService('_flutter.listViews', 'DWDS listViews');
84-
85-
client.registerServiceCallback('hotRestart', (request) async {
86-
_logger.info('Attempting a hot restart');
87-
88-
chromeProxyService.terminatingIsolates = true;
89-
await _disableBreakpointsAndResume(client, chromeProxyService);
90-
int context;
91-
try {
92-
_logger.info('Attempting to get execution context ID.');
93-
context = await chromeProxyService.executionContext.id;
94-
_logger.info('Got execution context ID.');
95-
} on StateError catch (e) {
96-
// We couldn't find the execution context. `hotRestart` may have been
97-
// triggered in the middle of a full reload.
98-
return {
99-
'error': {
100-
'code': RPCError.kInternalError,
101-
'message': e.message,
102-
}
103-
};
104-
}
105-
// Start listening for isolate create events before issuing a hot
106-
// restart. Only return success after the isolate has fully started.
107-
var stream = chromeProxyService.onEvent('Isolate');
108-
try {
109-
_logger.info('Issuing \$dartHotRestart request.');
110-
await chromeProxyService.remoteDebugger
111-
.sendCommand('Runtime.evaluate', params: {
112-
'expression': r'$dartHotRestart();',
113-
'awaitPromise': true,
114-
'contextId': context,
115-
});
116-
_logger.info('\$dartHotRestart request complete.');
117-
} on WipError catch (exception) {
118-
var code = exception.error['code'];
119-
// This corresponds to `Execution context was destroyed` which can
120-
// occur during a hot restart that must fall back to a full reload.
121-
if (code != RPCError.kServerError) {
122-
return {
123-
'error': {
124-
'code': exception.error['code'],
125-
'message': exception.error['message'],
126-
'data': exception,
127-
}
128-
};
129-
}
130-
}
83+
await client.registerService('_flutter.listViews', 'DWDS');
13184

132-
_logger.info('Waiting for Isolate Start event.');
133-
await stream.firstWhere((event) => event.kind == EventKind.kIsolateStart);
134-
chromeProxyService.terminatingIsolates = false;
135-
136-
_logger.info('Successful hot restart');
137-
return {'result': Success().toJson()};
138-
});
139-
await client.registerService('hotRestart', 'DWDS fullReload');
85+
client.registerServiceCallback(
86+
'hotRestart',
87+
(request) => captureElapsedTime(
88+
() => _hotRestart(chromeProxyService, client),
89+
(_) => DwdsEvent.hotRestart()));
90+
await client.registerService('hotRestart', 'DWDS');
14091

141-
client.registerServiceCallback('fullReload', (_) async {
142-
_logger.info('Attempting a full reload');
143-
await chromeProxyService.remoteDebugger.enablePage();
144-
await chromeProxyService.remoteDebugger.pageReload();
145-
_logger.info('Successful full reload');
146-
return {'result': Success().toJson()};
147-
});
92+
client.registerServiceCallback(
93+
'fullReload',
94+
(request) => captureElapsedTime(() => _fullReload(chromeProxyService),
95+
(_) => DwdsEvent.fullReload()));
14896
await client.registerService('fullReload', 'DWDS');
14997

15098
client.registerServiceCallback('ext.dwds.screenshot', (_) async {
@@ -205,6 +153,9 @@ void _processSendEvent(Map<String, dynamic> event,
205153
var action = payload == null ? null : payload['action'];
206154
if (screen == 'debugger' && action == 'pageReady') {
207155
if (dwdsStats.isFirstDebuggerReady()) {
156+
emitEvent(DwdsEvent.devToolsLoad(DateTime.now()
157+
.difference(dwdsStats.devToolsStart)
158+
.inMilliseconds));
208159
emitEvent(DwdsEvent.debuggerReady(DateTime.now()
209160
.difference(dwdsStats.debuggerStart)
210161
.inMilliseconds));
@@ -218,6 +169,71 @@ void _processSendEvent(Map<String, dynamic> event,
218169
}
219170
}
220171

172+
Future<Map<String, dynamic>> _hotRestart(
173+
ChromeProxyService chromeProxyService, VmService client) async {
174+
_logger.info('Attempting a hot restart');
175+
176+
chromeProxyService.terminatingIsolates = true;
177+
await _disableBreakpointsAndResume(client, chromeProxyService);
178+
int context;
179+
try {
180+
_logger.info('Attempting to get execution context ID.');
181+
context = await chromeProxyService.executionContext.id;
182+
_logger.info('Got execution context ID.');
183+
} on StateError catch (e) {
184+
// We couldn't find the execution context. `hotRestart` may have been
185+
// triggered in the middle of a full reload.
186+
return {
187+
'error': {
188+
'code': RPCError.kInternalError,
189+
'message': e.message,
190+
}
191+
};
192+
}
193+
// Start listening for isolate create events before issuing a hot
194+
// restart. Only return success after the isolate has fully started.
195+
var stream = chromeProxyService.onEvent('Isolate');
196+
try {
197+
_logger.info('Issuing \$dartHotRestart request.');
198+
await chromeProxyService.remoteDebugger
199+
.sendCommand('Runtime.evaluate', params: {
200+
'expression': r'$dartHotRestart();',
201+
'awaitPromise': true,
202+
'contextId': context,
203+
});
204+
_logger.info('\$dartHotRestart request complete.');
205+
} on WipError catch (exception) {
206+
var code = exception.error['code'];
207+
// This corresponds to `Execution context was destroyed` which can
208+
// occur during a hot restart that must fall back to a full reload.
209+
if (code != RPCError.kServerError) {
210+
return {
211+
'error': {
212+
'code': exception.error['code'],
213+
'message': exception.error['message'],
214+
'data': exception,
215+
}
216+
};
217+
}
218+
}
219+
220+
_logger.info('Waiting for Isolate Start event.');
221+
await stream.firstWhere((event) => event.kind == EventKind.kIsolateStart);
222+
chromeProxyService.terminatingIsolates = false;
223+
224+
_logger.info('Successful hot restart');
225+
return {'result': Success().toJson()};
226+
}
227+
228+
Future<Map<String, dynamic>> _fullReload(
229+
ChromeProxyService chromeProxyService) async {
230+
_logger.info('Attempting a full reload');
231+
await chromeProxyService.remoteDebugger.enablePage();
232+
await chromeProxyService.remoteDebugger.pageReload();
233+
_logger.info('Successful full reload');
234+
return {'result': Success().toJson()};
235+
}
236+
221237
Future<void> _disableBreakpointsAndResume(
222238
VmService client, ChromeProxyService chromeProxyService) async {
223239
_logger.info('Attempting to disable breakpoints and resume the isolate');

dwds/lib/src/events.dart

Lines changed: 44 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -12,6 +12,9 @@ class DwdsStats {
1212
/// The time when the user starts the debugger.
1313
final DateTime debuggerStart;
1414

15+
/// The time when dwds launches DevTools.
16+
DateTime devToolsStart;
17+
1518
var _isDebuggerReady = false;
1619

1720
/// Records and returns whether the debugger became ready.
@@ -28,13 +31,17 @@ class DwdsEventKind {
2831
static const String compilerUpdateDependencies =
2932
'COMPILER_UPDATE_DEPENDENCIES';
3033
static const String devtoolsLaunch = 'DEVTOOLS_LAUNCH';
34+
static const String devToolsLoad = 'DEVTOOLS_LOAD';
35+
static const String debuggerReady = 'DEBUGGER_READY';
3136
static const String evaluate = 'EVALUATE';
3237
static const String evaluateInFrame = 'EVALUATE_IN_FRAME';
38+
static const String fullReload = 'FULL_RELOAD';
3339
static const String getIsolate = 'GET_ISOLATE';
3440
static const String getScripts = 'GET_SCRIPTS';
3541
static const String getSourceReport = 'GET_SOURCE_REPORT';
36-
static const String debuggerReady = 'DEBUGGER_READY';
3742
static const String getVM = 'GET_VM';
43+
static const String hotRestart = 'HOT_RESTART';
44+
static const String httpRequestException = 'HTTP_REQUEST_EXCEPTION';
3845
static const String resume = 'RESUME';
3946

4047
DwdsEventKind._();
@@ -77,11 +84,26 @@ class DwdsEvent {
7784

7885
DwdsEvent.getSourceReport() : this(DwdsEventKind.getSourceReport, {});
7986

87+
DwdsEvent.hotRestart() : this(DwdsEventKind.hotRestart, {});
88+
89+
DwdsEvent.fullReload() : this(DwdsEventKind.fullReload, {});
90+
8091
DwdsEvent.debuggerReady(int elapsedMilliseconds)
8192
: this(DwdsEventKind.debuggerReady, {
8293
'elapsedMilliseconds': elapsedMilliseconds,
8394
});
8495

96+
DwdsEvent.devToolsLoad(int elapsedMilliseconds)
97+
: this(DwdsEventKind.devToolsLoad, {
98+
'elapsedMilliseconds': elapsedMilliseconds,
99+
});
100+
101+
DwdsEvent.httpRequestException(String server, String exception)
102+
: this(DwdsEventKind.httpRequestException, {
103+
'server': server,
104+
'exception': exception,
105+
});
106+
85107
void addException(dynamic exception) {
86108
payload['exception'] = exception;
87109
}
@@ -103,3 +125,24 @@ void emitEvent(DwdsEvent event) => _eventController.sink.add(event);
103125

104126
/// A global stream of [DwdsEvent]s.
105127
Stream<DwdsEvent> get eventStream => _eventController.stream;
128+
129+
/// Call [function] and record its execution time.
130+
///
131+
/// Calls [event] to create the event to be recorded,
132+
/// and appends time and exception details to it if
133+
/// available.
134+
Future<T> captureElapsedTime<T>(
135+
Future<T> Function() function, DwdsEvent Function(T result) event) async {
136+
var stopwatch = Stopwatch()..start();
137+
T result;
138+
try {
139+
return result = await function();
140+
} catch (e) {
141+
emitEvent(event(result)
142+
..addException(e)
143+
..addElapsedTime(stopwatch.elapsedMilliseconds));
144+
rethrow;
145+
} finally {
146+
emitEvent(event(result)..addElapsedTime(stopwatch.elapsedMilliseconds));
147+
}
148+
}

dwds/lib/src/handlers/dev_handler.dart

Lines changed: 6 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -221,8 +221,8 @@ class DevHandler {
221221
);
222222
}
223223

224-
Future<AppDebugServices> loadAppServices(AppConnection appConnection) async {
225-
var dwdsStats = DwdsStats(DateTime.now());
224+
Future<AppDebugServices> loadAppServices(
225+
AppConnection appConnection, DwdsStats dwdsStats) async {
226226
var appId = appConnection.request.appId;
227227
if (_servicesByAppId[appId] == null) {
228228
var debugService = await _startLocalDebugService(
@@ -321,9 +321,10 @@ class DevHandler {
321321
return;
322322
}
323323

324+
var dwdsStats = DwdsStats(DateTime.now());
324325
AppDebugServices appServices;
325326
try {
326-
appServices = await loadAppServices(appConnection);
327+
appServices = await loadAppServices(appConnection, dwdsStats);
327328
} catch (_) {
328329
var error = 'Unable to connect debug services to your '
329330
'application. Most likely this means you are trying to '
@@ -364,6 +365,7 @@ class DevHandler {
364365
..promptExtension = false))));
365366

366367
appServices.connectedInstanceId = appConnection.request.instanceId;
368+
dwdsStats.devToolsStart = DateTime.now();
367369
await _launchDevTools(appServices.chromeProxyService.remoteDebugger,
368370
appServices.debugService.uri);
369371
}
@@ -511,6 +513,7 @@ class DevHandler {
511513
extensionDebugConnections.add(DebugConnection(appServices));
512514
_servicesByAppId[appId] = appServices;
513515
}
516+
dwdsStats.devToolsStart = DateTime.now();
514517
await _launchDevTools(extensionDebugger,
515518
await _servicesByAppId[appId].debugService.encodedUri);
516519
});

dwds/lib/src/servers/extension_backend.dart

Lines changed: 4 additions & 3 deletions
Original file line numberDiff line numberDiff line change
@@ -8,20 +8,20 @@ import 'dart:async';
88
import 'dart:io';
99

1010
import 'package:async/async.dart';
11-
1211
import 'package:http_multi_server/http_multi_server.dart';
1312
import 'package:logging/logging.dart';
1413
import 'package:shelf/shelf.dart';
1514

1615
import '../../data/extension_request.dart';
16+
import '../events.dart';
1717
import '../handlers/socket_connections.dart';
1818
import '../utilities/shared.dart';
1919
import 'extension_debugger.dart';
2020

2121
const authenticationResponse = 'Dart Debug Authentication Success!\n\n'
2222
'You can close this tab and launch the Dart Debug Extension again.';
2323

24-
Logger _logger = Logger('ExtensiobBackend');
24+
Logger _logger = Logger('ExtensionBackend');
2525

2626
/// A backend for the Dart Debug Extension.
2727
///
@@ -56,7 +56,8 @@ class ExtensionBackend {
5656
}).add(_socketHandler.handler);
5757
var server = await HttpMultiServer.bind(hostname, 0);
5858
serveHttpRequests(server, cascade.handler, (e, s) {
59-
_logger.warning('Error serving requests', e, s);
59+
_logger.warning('Error serving requests', e);
60+
emitEvent(DwdsEvent.httpRequestException('ExtensionBackend', '$e:$s'));
6061
});
6162
return ExtensionBackend._(
6263
_socketHandler, server.address.host, server.port, server);

0 commit comments

Comments
 (0)