223 lines
8.6 KiB
Dart
223 lines
8.6 KiB
Dart
import 'dart:async';
|
|
|
|
import 'package:flutter_test/flutter_test.dart';
|
|
import 'package:pj_supermarket_cloud/common/utils/order/payment_timing_trace.dart';
|
|
|
|
void main() {
|
|
test('快速支付只输出一条包含全部阶段的汇总，重复结束不追加日志', () async {
|
|
final logs = <String>[];
|
|
var elapsed = Duration.zero;
|
|
final trace = PaymentTimingTrace(
|
|
log: logs.add,
|
|
id: 'checkout-a',
|
|
elapsed: () => elapsed,
|
|
);
|
|
final result = await trace.run(() async {
|
|
PaymentTimingTrace.setCurrentOrderCode('android_123_456');
|
|
return trace.measure('discounts', () async {
|
|
elapsed = const Duration(milliseconds: 75);
|
|
return PaymentTimingTrace.measureCurrent('local_sql', () async {
|
|
elapsed = const Duration(milliseconds: 125);
|
|
return 'paid';
|
|
});
|
|
});
|
|
});
|
|
trace.finish(outcome: 'success');
|
|
trace.finish(outcome: 'failed');
|
|
|
|
expect(result, 'paid');
|
|
expect(logs, hasLength(1));
|
|
expect(logs.single, contains('trace:checkout-a'));
|
|
expect(logs.single, contains('androidOrderCode:android_123_456'));
|
|
expect(logs.single, contains('outcome:success|totalMs:125'));
|
|
expect(
|
|
logs.single, contains('stagesInclusiveMs:discounts=125,local_sql=50'));
|
|
expect(logs.single, contains('pending:-|errorTypes:-'));
|
|
});
|
|
|
|
test('并发异步支付和嵌套追踪各自使用所在 Zone，不会串单', () async {
|
|
final firstLogs = <String>[];
|
|
final secondLogs = <String>[];
|
|
final first = PaymentTimingTrace(log: firstLogs.add, id: 'first');
|
|
final second = PaymentTimingTrace(log: secondLogs.add, id: 'second');
|
|
final firstReady = Completer<void>();
|
|
final secondReady = Completer<void>();
|
|
|
|
await Future.wait([
|
|
first.run(() async {
|
|
PaymentTimingTrace.setCurrentOrderCode('order_first');
|
|
firstReady.complete();
|
|
await secondReady.future;
|
|
expect(PaymentTimingTrace.current, same(first));
|
|
await second.run(() async {
|
|
expect(PaymentTimingTrace.current, same(second));
|
|
});
|
|
expect(PaymentTimingTrace.current, same(first));
|
|
await PaymentTimingTrace.measureCurrent('first_stage', () async {});
|
|
}),
|
|
second.run(() async {
|
|
PaymentTimingTrace.setCurrentOrderCode('order_second');
|
|
secondReady.complete();
|
|
await firstReady.future;
|
|
expect(PaymentTimingTrace.current, same(second));
|
|
await PaymentTimingTrace.measureCurrent('second_stage', () async {});
|
|
}),
|
|
]);
|
|
first.finish(outcome: 'success');
|
|
second.finish(outcome: 'success');
|
|
|
|
expect(PaymentTimingTrace.current, isNull);
|
|
expect(firstLogs.single, contains('androidOrderCode:order_first'));
|
|
expect(firstLogs.single, contains('first_stage='));
|
|
expect(firstLogs.single, isNot(contains('second_stage')));
|
|
expect(secondLogs.single, contains('androidOrderCode:order_second'));
|
|
expect(secondLogs.single, contains('second_stage='));
|
|
});
|
|
|
|
testWidgets('看门狗只报告一次，慢阶段结束后停止等待并输出实际耗时', (tester) async {
|
|
final logs = <String>[];
|
|
var elapsed = Duration.zero;
|
|
final trace = PaymentTimingTrace(log: logs.add, elapsed: () => elapsed);
|
|
final source = Completer<int>();
|
|
final work = trace.measure('http_order', () => source.future);
|
|
|
|
elapsed = const Duration(milliseconds: 1000);
|
|
await tester.pump(const Duration(seconds: 1));
|
|
expect(logs, hasLength(1));
|
|
expect(
|
|
logs.single, contains('event:pending|stage:http_order|elapsedMs:1000'));
|
|
elapsed = const Duration(milliseconds: 4500);
|
|
await tester.pump(const Duration(milliseconds: 3500));
|
|
expect(logs, hasLength(1));
|
|
source.complete(7);
|
|
expect(await work, 7);
|
|
trace.finish(outcome: 'success');
|
|
await tester.pump(const Duration(seconds: 5));
|
|
|
|
expect(logs, hasLength(3));
|
|
expect(logs[1], contains('event:stage|stage:http_order|costMs:4500'));
|
|
expect(logs[2], contains('totalMs:4500|stagesInclusiveMs:http_order=4500'));
|
|
});
|
|
|
|
testWidgets('结束追踪取消尚未完成阶段的看门狗，后续完成不再写日志', (tester) async {
|
|
final logs = <String>[];
|
|
var elapsed = Duration.zero;
|
|
final trace = PaymentTimingTrace(log: logs.add, elapsed: () => elapsed);
|
|
final source = Completer<void>();
|
|
final work = trace.measure('pending_sql', () => source.future);
|
|
elapsed = const Duration(milliseconds: 150);
|
|
trace.finish(outcome: 'failed');
|
|
await tester.pump(const Duration(seconds: 5));
|
|
source.complete();
|
|
await work;
|
|
|
|
expect(logs, hasLength(1));
|
|
expect(logs.single, contains('outcome:failed|totalMs:150'));
|
|
expect(logs.single, contains('pending:pending_sql'));
|
|
});
|
|
|
|
testWidgets('等待网络四点五秒但事件循环正常时，调度延迟保持零', (tester) async {
|
|
final logs = <String>[];
|
|
var elapsed = Duration.zero;
|
|
final trace = PaymentTimingTrace(log: logs.add, elapsed: () => elapsed);
|
|
final source = Completer<void>();
|
|
final work = trace.measure('http_order', () => source.future);
|
|
for (var tick = 1; tick <= 18; tick++) {
|
|
elapsed = Duration(milliseconds: tick * 250);
|
|
await tester.pump(const Duration(milliseconds: 250));
|
|
}
|
|
source.complete();
|
|
await work;
|
|
trace.finish(outcome: 'offline_accepted');
|
|
|
|
expect(logs.last, contains('outcome:offline_accepted|totalMs:4500'));
|
|
expect(logs.last, contains('eventLoopLagMs:0'));
|
|
expect(logs.where((line) => line.contains('event:pending')), hasLength(1));
|
|
});
|
|
|
|
testWidgets('同步阻塞结束后尚未派发探针时，结束追踪仍捕获最后一段调度延迟', (tester) async {
|
|
final logs = <String>[];
|
|
var elapsed = Duration.zero;
|
|
final trace = PaymentTimingTrace(log: logs.add, elapsed: () => elapsed);
|
|
expect(
|
|
trace.measureSync('json_prepare', () {
|
|
elapsed = const Duration(milliseconds: 4500);
|
|
return 'paid';
|
|
}),
|
|
'paid',
|
|
);
|
|
trace.finish(outcome: 'success');
|
|
await tester.pump(const Duration(seconds: 5));
|
|
|
|
expect(logs, hasLength(2));
|
|
expect(logs.last, contains('eventLoopLagMs:4250'));
|
|
expect(logs.where((line) => line.contains('event:pending')), isEmpty);
|
|
});
|
|
|
|
testWidgets('失败保持原异常对象和堆栈，不输出异常内容并取消看门狗', (tester) async {
|
|
final logs = <String>[];
|
|
final trace = PaymentTimingTrace(log: logs.add);
|
|
final failure = StateError('secret-wallet-token');
|
|
final originalStack = StackTrace.fromString('original-payment-stack');
|
|
Object? caught;
|
|
StackTrace? caughtStack;
|
|
try {
|
|
await trace.measure(
|
|
'http_order', () => Future<void>.error(failure, originalStack));
|
|
} catch (error, stack) {
|
|
caught = error;
|
|
caughtStack = stack;
|
|
} finally {
|
|
trace.finish(outcome: 'exception');
|
|
}
|
|
await tester.pump(const Duration(seconds: 5));
|
|
|
|
expect(caught, same(failure));
|
|
expect(caughtStack.toString(), originalStack.toString());
|
|
expect(logs, hasLength(2));
|
|
expect(logs.first, contains('errorType:StateError'));
|
|
expect(logs.last, contains('errorTypes:StateError'));
|
|
expect(logs.join(), isNot(contains('secret-wallet-token')));
|
|
expect(logs.join(), isNot(contains('original-payment-stack')));
|
|
});
|
|
|
|
test('日志故障、回退时钟和不安全元数据不能改变原业务返回值', () async {
|
|
var elapsed = const Duration(milliseconds: 200);
|
|
final logs = <String>[];
|
|
final trace = PaymentTimingTrace(
|
|
log: (message) {
|
|
logs.add(message);
|
|
throw StateError('logger offline');
|
|
},
|
|
elapsed: () => elapsed,
|
|
id: 'invalid\nsecret',
|
|
);
|
|
final result = await trace.run(() async {
|
|
PaymentTimingTrace.setCurrentOrderCode('invalid|token=secret');
|
|
return trace.measure('first', () async {
|
|
elapsed = const Duration(milliseconds: 50);
|
|
return trace.measureSync('second', () => 42);
|
|
});
|
|
});
|
|
trace.finish(outcome: 'invalid\nsecret');
|
|
|
|
expect(result, 42);
|
|
expect(logs, hasLength(1));
|
|
expect(logs.single, contains('totalMs:200'));
|
|
expect(logs.single, contains('first=0,second=0'));
|
|
expect(logs.single, contains('outcome:unknown'));
|
|
expect(logs.single, isNot(contains('secret')));
|
|
});
|
|
|
|
test('没有追踪或追踪已经结束时按原样执行共享下单回调', () async {
|
|
expect(await PaymentTimingTrace.measureCurrent('unused', () async => 6), 6);
|
|
expect(PaymentTimingTrace.measureSyncCurrent('unused', () => 7), 7);
|
|
final logs = <String>[];
|
|
final trace = PaymentTimingTrace(log: logs.add);
|
|
trace.finish(outcome: 'success');
|
|
expect(await trace.measure('unused', () async => 8), 8);
|
|
expect(trace.measureSync('unused', () => 9), 9);
|
|
expect(logs, hasLength(1));
|
|
});
|
|
}
|