blob: f7638801b8e49c6a44d1a409b7d606ba58c7dfa2 [file] [log] [blame]
// Copyright 2014 The Flutter Authors. All rights reserved.
// Use of this source code is governed by a BSD-style license that can be
// found in the LICENSE file.
import 'dart:async';
import 'package:fake_async/fake_async.dart';
import 'package:file/memory.dart';
import 'package:file_testing/file_testing.dart';
import 'package:flutter_tools/src/base/file_system.dart';
import 'package:flutter_tools/src/base/logger.dart';
import 'package:flutter_tools/src/convert.dart';
import 'package:flutter_tools/src/tracing.dart';
import 'package:flutter_tools/src/vmservice.dart';
import 'package:vm_service/vm_service.dart' as vm_service;
import '../src/common.dart';
import '../src/fake_vm_services.dart';
final vm_service.Isolate fakeUnpausedIsolate = vm_service.Isolate(
id: '1',
pauseEvent: vm_service.Event(
kind: vm_service.EventKind.kResume,
timestamp: 0
),
breakpoints: <vm_service.Breakpoint>[],
libraries: <vm_service.LibraryRef>[
vm_service.LibraryRef(
id: '1',
uri: 'file:///hello_world/main.dart',
name: '',
),
],
livePorts: 0,
name: 'test',
number: '1',
pauseOnExit: false,
runnable: true,
startTime: 0,
isSystemIsolate: false,
isolateFlags: <vm_service.IsolateFlag>[],
);
final FlutterView fakeFlutterView = FlutterView(
id: 'a',
uiIsolate: fakeUnpausedIsolate,
);
final FakeVmServiceRequest listViews = FakeVmServiceRequest(
method: kListViewsMethod,
jsonResponse: <String, Object>{
'views': <Object>[
fakeFlutterView.toJson(),
],
},
);
final List<FakeVmServiceRequest> vmServiceSetup = <FakeVmServiceRequest>[
const FakeVmServiceRequest(
method: 'streamListen',
args: <String, Object>{
'streamId': vm_service.EventKind.kExtension,
}
),
listViews,
// Satisfies didAwaitFirstFrame
const FakeVmServiceRequest(
method: 'ext.flutter.didSendFirstFrameRasterizedEvent',
args: <String, Object>{
'isolateId': '1',
},
jsonResponse: <String, Object>{
'enabled': 'true',
},
),
];
void main() {
testWithoutContext('Can trace application startup', () async {
final BufferLogger logger = BufferLogger.test();
final FileSystem fileSystem = MemoryFileSystem.test();
final FakeVmServiceHost fakeVmServiceHost = FakeVmServiceHost(requests: <FakeVmServiceRequest>[
...vmServiceSetup,
FakeVmServiceRequest(
method: 'getVMTimeline',
jsonResponse: vm_service.Timeline(
timeExtentMicros: 4,
timeOriginMicros: 0,
traceEvents: <vm_service.TimelineEvent>[
vm_service.TimelineEvent.parse(<String, Object>{
'name': kFlutterEngineMainEnterEventName,
'ts': 0,
})!,
vm_service.TimelineEvent.parse(<String, Object>{
'name': kFrameworkInitEventName,
'ts': 1,
})!,
vm_service.TimelineEvent.parse(<String, Object>{
'name': kFirstFrameBuiltEventName,
'ts': 2,
})!,
vm_service.TimelineEvent.parse(<String, Object>{
'name': kFirstFrameRasterizedEventName,
'ts': 3,
})!,
],
).toJson(),
),
const FakeVmServiceRequest(
method: 'setVMTimelineFlags',
args: <String, Object>{
'recordedStreams': <Object>[],
},
),
]);
// Validate that old tracing data is deleted.
final File outFile = fileSystem.currentDirectory.childFile('start_up_info.json')
..writeAsStringSync('stale');
await downloadStartupTrace(fakeVmServiceHost.vmService,
output: fileSystem.currentDirectory,
logger: logger,
);
expect(outFile, exists);
expect(json.decode(outFile.readAsStringSync()), <String, Object>{
'engineEnterTimestampMicros': 0,
'timeToFrameworkInitMicros': 1,
'timeToFirstFrameRasterizedMicros': 3,
'timeToFirstFrameMicros': 2,
'timeAfterFrameworkInitMicros': 1,
});
});
testWithoutContext('throws tool exit if the vmservice disconnects', () async {
final BufferLogger logger = BufferLogger.test();
final FileSystem fileSystem = MemoryFileSystem.test();
final FakeVmServiceHost fakeVmServiceHost = FakeVmServiceHost(requests: <FakeVmServiceRequest>[
...vmServiceSetup,
const FakeVmServiceRequest(
method: 'getVMTimeline',
errorCode: RPCErrorCodes.kServiceDisappeared,
),
const FakeVmServiceRequest(
method: 'setVMTimelineFlags',
args: <String, Object>{
'recordedStreams': <Object>[],
},
),
]);
await expectLater(() async => downloadStartupTrace(fakeVmServiceHost.vmService,
output: fileSystem.currentDirectory,
logger: logger,
), throwsToolExit(message: 'The device disconnected before the timeline could be retrieved.'));
});
testWithoutContext('throws tool exit if timeline is missing the engine start event', () async {
final BufferLogger logger = BufferLogger.test();
final FileSystem fileSystem = MemoryFileSystem.test();
final FakeVmServiceHost fakeVmServiceHost = FakeVmServiceHost(requests: <FakeVmServiceRequest>[
...vmServiceSetup,
FakeVmServiceRequest(
method: 'getVMTimeline',
jsonResponse: vm_service.Timeline(
timeExtentMicros: 4,
timeOriginMicros: 0,
traceEvents: <vm_service.TimelineEvent>[],
).toJson(),
),
const FakeVmServiceRequest(
method: 'setVMTimelineFlags',
args: <String, Object>{
'recordedStreams': <Object>[],
},
),
]);
await expectLater(() async => downloadStartupTrace(fakeVmServiceHost.vmService,
output: fileSystem.currentDirectory,
logger: logger,
), throwsToolExit(message: 'Engine start event is missing in the timeline'));
});
testWithoutContext('prints when first frame is taking a long time', () async {
final BufferLogger logger = BufferLogger.test();
final FileSystem fileSystem = MemoryFileSystem.test();
final Completer<void> completer = Completer<void>();
await FakeAsync().run((FakeAsync time) {
final Map<String, String> extensionData = <String, String>{
'test': 'data',
'renderedErrorText': 'error text',
};
final FakeVmServiceHost fakeVmServiceHost = FakeVmServiceHost(requests: <VmServiceExpectation>[
const FakeVmServiceRequest(
method: 'streamListen',
args: <String, Object>{
'streamId': vm_service.EventKind.kExtension,
}
),
const FakeVmServiceRequest(
method: kListViewsMethod,
jsonResponse: <String, Object>{
'views': <Object>[
<String, Object?>{
'id': '1',
// No isolate, no views.
'isolate': null,
}
],
},
),
FakeVmServiceStreamResponse(
streamId: 'Extension',
event: vm_service.Event(
timestamp: 0,
extensionKind: 'Flutter.Error',
extensionData: vm_service.ExtensionData.parse(extensionData),
kind: vm_service.EventStreams.kExtension,
),
),
]);
unawaited(downloadStartupTrace(fakeVmServiceHost.vmService,
output: fileSystem.currentDirectory,
logger: logger,
));
time.elapse(const Duration(seconds: 11));
time.flushMicrotasks();
completer.complete();
return completer.future;
});
expect(logger.statusText, contains('First frame is taking longer than expected'));
expect(logger.traceText, contains('View ID: 1'));
expect(logger.traceText, contains('No isolate ID associated with the view'));
expect(logger.traceText, contains('Flutter.Error: [ExtensionData {test: data, renderedErrorText: error text}]'));
});
testWithoutContext('throws tool exit if first frame events are missing', () async {
final BufferLogger logger = BufferLogger.test();
final FileSystem fileSystem = MemoryFileSystem.test();
final FakeVmServiceHost fakeVmServiceHost = FakeVmServiceHost(requests: <FakeVmServiceRequest>[
...vmServiceSetup,
FakeVmServiceRequest(
method: 'getVMTimeline',
jsonResponse: vm_service.Timeline(
timeExtentMicros: 4,
timeOriginMicros: 0,
traceEvents: <vm_service.TimelineEvent>[
vm_service.TimelineEvent.parse(<String, Object>{
'name': kFlutterEngineMainEnterEventName,
'ts': 0,
})!,
vm_service.TimelineEvent.parse(<String, Object>{
'name': kFrameworkInitEventName,
'ts': 1,
})!,
],
).toJson(),
),
const FakeVmServiceRequest(
method: 'setVMTimelineFlags',
args: <String, Object>{
'recordedStreams': <Object>[],
},
),
]);
await expectLater(() async => downloadStartupTrace(fakeVmServiceHost.vmService,
output: fileSystem.currentDirectory,
logger: logger,
), throwsToolExit(message: 'First frame events are missing in the timeline'));
});
testWithoutContext('Can trace application startup without awaiting for first frame', () async {
final BufferLogger logger = BufferLogger.test();
final FileSystem fileSystem = MemoryFileSystem.test();
final FakeVmServiceHost fakeVmServiceHost = FakeVmServiceHost(requests: <FakeVmServiceRequest>[
FakeVmServiceRequest(
method: 'getVMTimeline',
jsonResponse: vm_service.Timeline(
timeExtentMicros: 4,
timeOriginMicros: 0,
traceEvents: <vm_service.TimelineEvent>[
vm_service.TimelineEvent.parse(<String, Object>{
'name': kFlutterEngineMainEnterEventName,
'ts': 0,
})!,
vm_service.TimelineEvent.parse(<String, Object>{
'name': kFrameworkInitEventName,
'ts': 1,
})!,
],
).toJson(),
),
const FakeVmServiceRequest(
method: 'setVMTimelineFlags',
args: <String, Object>{
'recordedStreams': <Object>[],
},
),
]);
final File outFile = fileSystem.currentDirectory.childFile('start_up_info.json');
await downloadStartupTrace(fakeVmServiceHost.vmService,
output: fileSystem.currentDirectory,
logger: logger,
awaitFirstFrame: false,
);
expect(outFile, exists);
expect(json.decode(outFile.readAsStringSync()), <String, Object>{
'engineEnterTimestampMicros': 0,
'timeToFrameworkInitMicros': 1,
});
});
testWithoutContext('downloadStartupTrace also downloads the timeline', () async {
final BufferLogger logger = BufferLogger.test();
final FileSystem fileSystem = MemoryFileSystem.test();
final FakeVmServiceHost fakeVmServiceHost = FakeVmServiceHost(requests: <FakeVmServiceRequest>[
...vmServiceSetup,
FakeVmServiceRequest(
method: 'getVMTimeline',
jsonResponse: vm_service.Timeline(
timeExtentMicros: 4,
timeOriginMicros: 0,
traceEvents: <vm_service.TimelineEvent>[
vm_service.TimelineEvent.parse(<String, Object>{
'name': kFlutterEngineMainEnterEventName,
'ts': 0,
})!,
vm_service.TimelineEvent.parse(<String, Object>{
'name': kFrameworkInitEventName,
'ts': 1,
})!,
vm_service.TimelineEvent.parse(<String, Object>{
'name': kFirstFrameBuiltEventName,
'ts': 2,
})!,
vm_service.TimelineEvent.parse(<String, Object>{
'name': kFirstFrameRasterizedEventName,
'ts': 3,
})!,
],
).toJson(),
),
const FakeVmServiceRequest(
method: 'setVMTimelineFlags',
args: <String, Object>{
'recordedStreams': <Object>[],
},
),
]);
// Validate that old tracing data is deleted.
final File timelineFile = fileSystem.currentDirectory.childFile('start_up_timeline.json')
..writeAsStringSync('stale');
await downloadStartupTrace(fakeVmServiceHost.vmService,
output: fileSystem.currentDirectory,
logger: logger,
);
final Map<String, Object> expectedTimeline = <String, Object>{
'type': 'Timeline',
'traceEvents': <Object>[
<String, Object>{
'name': 'FlutterEngineMainEnter',
'ts': 0,
'type': 'TimelineEvent',
},
<String, Object>{
'name': 'Framework initialization',
'ts': 1,
'type': 'TimelineEvent',
},
<String, Object>{
'name': 'Widgets built first useful frame',
'ts': 2,
'type': 'TimelineEvent',
},
<String, Object>{
'name': 'Rasterized first useful frame',
'ts': 3,
'type': 'TimelineEvent',
},
],
'timeOriginMicros': 0,
'timeExtentMicros': 4,
};
expect(timelineFile, exists);
expect(json.decode(timelineFile.readAsStringSync()), expectedTimeline);
});
}