Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[Flutter] startTransaction slows down grpc Requests on windows #2760

Open
Knupper opened this issue Feb 28, 2025 · 26 comments
Open

[Flutter] startTransaction slows down grpc Requests on windows #2760

Knupper opened this issue Feb 28, 2025 · 26 comments
Assignees

Comments

@Knupper
Copy link

Knupper commented Feb 28, 2025

Platform

Flutter Desktop Windows

Obfuscation

Enabled

Debug Info

Enabled

Doctor

PS C:\Users\knupp\IdeaProjects\One.frontend> flutter doctor -v
[√] Flutter (Channel stable, 3.27.3, on Microsoft Windows [Version 10.0.22631.4830], locale de-DE)
• Flutter version 3.27.3 on channel stable at C:\development\flutter
• Upstream repository https://github.com/flutter/flutter.git
• Framework revision c519ee916e (5 weeks ago), 2025-01-21 10:32:23 -0800
• Engine revision e672b006cb
• Dart version 3.6.1
• DevTools version 2.40.2

[√] Windows Version (Installed version of Windows is version 10 or higher)

[√] Android toolchain - develop for Android devices (Android SDK version 35.0.1)
• Android SDK at C:\Users\knupp\AppData\Local\Android\Sdk
• Platform android-35, build-tools 35.0.1
• ANDROID_SDK_ROOT = C:\Users\knupp\AppData\Local\Android\Sdk
• Java binary at: C:\Program Files\Android\Android Studio1\jbr\bin\java
• Java version OpenJDK Runtime Environment (build 17.0.7+0-b2043.56-10550314)
• All Android licenses accepted.

[√] Chrome - develop for the web
• Chrome at C:\Program Files\Google\Chrome\Application\chrome.exe

[√] Visual Studio - develop Windows apps (Visual Studio Community 2022 17.12.5)
• Visual Studio at C:\Program Files\Microsoft Visual Studio\2022\Community
• Visual Studio Community 2022 version 17.12.35728.132
• Windows 10 SDK version 10.0.26100.0

[√] Android Studio (version 2023.1)
• Android Studio at C:\Program Files\Android\Android Studio1
• Flutter plugin can be installed from:
https://plugins.jetbrains.com/plugin/9212-flutter
• Dart plugin can be installed from:
https://plugins.jetbrains.com/plugin/6351-dart
• Java version OpenJDK Runtime Environment (build 17.0.7+0-b2043.56-10550314)

[!] Android Studio (version 4.1)
• Android Studio at C:\Program Files\Android\Android Studio
• Flutter plugin can be installed from:
https://plugins.jetbrains.com/plugin/9212-flutter
• Dart plugin can be installed from:
https://plugins.jetbrains.com/plugin/6351-dart
X Unable to determine bundled Java version.
• Try updating or re-installing Android Studio.

[√] IntelliJ IDEA Ultimate Edition (version 2024.3)
• IntelliJ at C:\Program Files\JetBrains\IntelliJ IDEA 2023.3.3
• Flutter plugin version 83.0.4
• Dart plugin version 243.23654.44

[√] Connected device (3 available)
• Windows (desktop) • windows • windows-x64 • Microsoft Windows [Version 10.0.22631.4830]
• Chrome (web) • chrome • web-javascript • Google Chrome 133.0.6943.142
• Edge (web) • edge • web-javascript • Microsoft Edge 132.0.2957.115

[√] Network resources
• All expected network resources are available.

! Doctor found issues in 1 category.

Version

8.13.0

Steps to Reproduce

  1. Create a Interceptor for a GRPC Client
  2. override interceptUnary and call Sentry.startTransaction there and return the result with a then that then finish the transaction (example see below)
  3. Start your app on windows
  4. fetch data
class SentryPerformanceInterceptor extends ClientInterceptor {
  static double traceSampleRate = 1.0;

  SentryPerformanceInterceptor();

  @override
  ResponseStream<R> interceptStreaming<Q, R>(
    ClientMethod<Q, R> method,
    Stream<Q> requests,
    CallOptions options,
    ClientStreamingInvoker<Q, R> invoker,
  ) {
    return invoker(method, requests, options);
  }

  @override
  ResponseFuture<R> interceptUnary<Q, R>(
    ClientMethod<Q, R> method,
    Q request,
    CallOptions options,
    ClientUnaryInvoker<Q, R> invoker,
  ) {
    final transaction = Sentry.startTransaction('service', 'method');

    final result = invoker(method, request, options);

    return result
      ..then(
        (_) {
          transaction.finish();
        },
        onError: (error) {
          transaction.throwable = error;
          transaction.status = SpanStatus.unknownError();
          transaction.finish();
        },
      );
  }
}

Expected Result

The runtime of each call should be not longer then without the interceptor.

Actual Result

On Windows it takes much more time to complete all requests.

Here is a example app, that opens 200 connections to one service and meassures how long it takes that alle calls are completed. With the buttons we can decice if we want to use the interceptor with sentry or not.

Here are the results from windows (sampleRate: 1):

Image

windows (SampleRate 0.2)

Image

For mac:

Image

For android:

Image

For ios:

Image

For web:

Image

As we see the performance impact on all platforms is very small for enabling tracing. Only for windows it has a huge impact and that looks like a bug for me.

I hope you have enough information to reproduce it, if not let me know.

import 'package:flutter/foundation.dart';
import 'package:flutter/material.dart';
import 'package:flutter_bloc/flutter_bloc.dart';

class TestResult {
  final Duration totalDuration;
  final Duration averageDuration;

  TestResult({
    required this.totalDuration,
    required this.averageDuration,
  });
}

class PerformanceState {
  final bool isLoading;
  final TestResult? withSentryResult;
  final TestResult? withoutSentryResult;

  PerformanceState({
    this.isLoading = false,
    this.withSentryResult,
    this.withoutSentryResult,
  });

  PerformanceState copyWith({
    bool? isLoading,
    TestResult? withSentryResult,
    TestResult? withoutSentryResult,
  }) {
    return PerformanceState(
      isLoading: isLoading ?? this.isLoading,
      withSentryResult: withSentryResult ?? this.withSentryResult,
      withoutSentryResult: withoutSentryResult ?? this.withoutSentryResult,
    );
  }
}

class PerformanceCubit extends Cubit<PerformanceState> {
  PerformanceCubit() : super(PerformanceState());

  Future<void> runPerformanceTest({
    required bool useSentryInterceptor,
  }) async {
    emit(state.copyWith(isLoading: true));

    final List<ClientInterceptor> interceptors = useSentryInterceptor ? [SentryPerformanceInterceptor()] : [];
    final repository = GrpcApi(
      interceptors: interceptors,
    );

    const iterations = 200;
    final futures = <Future>[];
    final durations = <Duration>[];

    final stopwatch = Stopwatch()..start();
    for (var i = 0; i < iterations; i++) {
      futures.add(repository.client.readCountries(ReadCountriesRequest()));
      durations.add(stopwatch.elapsed);
    }


    await Future.wait(futures);

    stopwatch.stop();

    final totalDuration = stopwatch.elapsed;
    final averageDuration = Duration(microseconds: totalDuration.inMicroseconds ~/ iterations);

    final result = TestResult(
      totalDuration: totalDuration,
      averageDuration: averageDuration,
    );

    emit(state.copyWith(
      isLoading: false,
      withSentryResult: useSentryInterceptor ? result : state.withSentryResult,
      withoutSentryResult: useSentryInterceptor ? state.withoutSentryResult : result,
    ));
  }
}

class PerformanceTestApp extends StatelessWidget {
  const PerformanceTestApp({super.key});

  @override
  Widget build(BuildContext context) {
    return MaterialApp(
      home: BlocProvider(
        create: (context) => PerformanceCubit(),
        child: const PerformanceTestScreen(),
      ),
    );
  }
}

class PerformanceTestScreen extends StatelessWidget {
  const PerformanceTestScreen({super.key});

  @override
  Widget build(BuildContext context) {
    return Scaffold(
      appBar: AppBar(
        title: const Text('Performance Test'),
      ),
      body: Padding(
        padding: const EdgeInsets.all(16.0),
        child: BlocBuilder<PerformanceCubit, PerformanceState>(
          builder: (context, state) {
            return Column(
              crossAxisAlignment: CrossAxisAlignment.stretch,
              children: [
                Row(
                  children: [
                    Expanded(
                      child: ElevatedButton(
                        onPressed: state.isLoading
                            ? null
                            : () => context.read<PerformanceCubit>().runPerformanceTest(useSentryInterceptor: false),
                        child: const Text('Test Without Sentry'),
                      ),
                    ),
                    const SizedBox(width: 16),
                    Expanded(
                      child: ElevatedButton(
                        onPressed: state.isLoading
                            ? null
                            : () => context.read<PerformanceCubit>().runPerformanceTest(useSentryInterceptor: true),
                        child: const Text('Test With Sentry'),
                      ),
                    ),
                  ],
                ),
                const SizedBox(height: 32),
                if (state.isLoading)
                  const Center(child: CircularProgressIndicator())
                else ...[
                  if (state.withoutSentryResult != null)
                    Card(
                      child: Padding(
                        padding: const EdgeInsets.all(16.0),
                        child: Column(
                          crossAxisAlignment: CrossAxisAlignment.start,
                          children: [
                            Text(
                              'Results Without Sentry:',
                              style: Theme.of(context).textTheme.titleLarge,
                            ),
                            const SizedBox(height: 8),
                            Text(
                              'Total time: ${state.withoutSentryResult!.totalDuration.inMilliseconds}ms',
                              style: Theme.of(context).textTheme.bodyLarge,
                            ),
                            const SizedBox(height: 4),
                            Text(
                              'Average time per call: ${state.withoutSentryResult!.averageDuration.inMilliseconds}ms',
                              style: Theme.of(context).textTheme.bodyLarge,
                            ),
                          ],
                        ),
                      ),
                    ),
                  if (state.withSentryResult != null) ...[
                    const SizedBox(height: 16),
                    Card(
                      child: Padding(
                        padding: const EdgeInsets.all(16.0),
                        child: Column(
                          crossAxisAlignment: CrossAxisAlignment.start,
                          children: [
                            Text(
                              'Results With Sentry:',
                              style: Theme.of(context).textTheme.titleLarge,
                            ),
                            const SizedBox(height: 8),
                            Text(
                              'Total time: ${state.withSentryResult!.totalDuration.inMilliseconds}ms',
                              style: Theme.of(context).textTheme.bodyLarge,
                            ),
                            const SizedBox(height: 4),
                            Text(
                              'Average time per call: ${state.withSentryResult!.averageDuration.inMilliseconds}ms',
                              style: Theme.of(context).textTheme.bodyLarge,
                            ),
                          ],
                        ),
                      ),
                    ),
                  ],
                  if (state.withSentryResult != null && state.withoutSentryResult != null) ...[
                    const SizedBox(height: 16),
                    Card(
                      child: Padding(
                        padding: const EdgeInsets.all(16.0),
                        child: Column(
                          crossAxisAlignment: CrossAxisAlignment.start,
                          children: [
                            Text(
                              'Performance Impact:',
                              style: Theme.of(context).textTheme.titleLarge,
                            ),
                            const SizedBox(height: 8),
                            Text(
                              'Difference in total time: ${(state.withSentryResult!.totalDuration - state.withoutSentryResult!.totalDuration).inMilliseconds}ms',
                              style: Theme.of(context).textTheme.bodyLarge,
                            ),
                            const SizedBox(height: 4),
                            Text(
                              'Difference in average time: ${(state.withSentryResult!.averageDuration - state.withoutSentryResult!.averageDuration).inMilliseconds}ms',
                              style: Theme.of(context).textTheme.bodyLarge,
                            ),
                          ],
                        ),
                      ),
                    ),
                  ],
                ],
              ],
            );
          },
        ),
      ),
    );
  }
}

Future<void> main() async {

  await SentryFlutter.init(
        (options) {
      options.dsn = 'URL;
      options.environment = 'test';
      options.debug = kDebugMode;
      options.diagnosticLevel = SentryLevel.info;
      options.tracesSampleRate = 0.2;  // 1.0 has a much worse result
    },
    appRunner: () async {
      WidgetsFlutterBinding.ensureInitialized();

      runApp(const PerformanceTestApp());
    },
  );
}

Minimal Example: https://github.com/Knupper/sentry-windows-mvp

Are you willing to submit a PR?

None

@kahest
Copy link
Member

kahest commented Feb 28, 2025

@Knupper thank you for the detailed report and the repro, that's really helpful and appreciated. We'll look into this and follow up here.

@denrase
Copy link
Collaborator

denrase commented Feb 28, 2025

@Knupper thx for all the details! i will check this out and get back to you 🙇

@kahest kahest moved this from Needs Discussion to Needs Investigation in Mobile SDKs Feb 28, 2025
@denrase denrase moved this from Needs Investigation to In Investigation in Mobile SDKs Mar 3, 2025
@denrase
Copy link
Collaborator

denrase commented Mar 4, 2025

Think i got it. We are adding device info to every transaction. On windows/linux machines we run a process to get memory size in our PlatformMemory class. So it makes sense that this is the bottleneck. I'll think about how to handle this. We can either cache this value for a short period or try to come up with something thats not blocking for so long.

@denrase
Copy link
Collaborator

denrase commented Mar 4, 2025

@kahest What do you think would the best approach be here?

  • Disable the memory collection per default or in options
  • Cache memory for x seconds
  • Research if there is a faster approach to read system memory

@denrase denrase moved this from In Investigation to Needs Discussion in Mobile SDKs Mar 4, 2025
@kahest
Copy link
Member

kahest commented Mar 4, 2025

@denrase can you clarify "get memory size in our PlatformMemory class" - is this system RAM? if so, we can just cache it, it won't change on the fly too often :)
otherwise I think all your approaches (maybe in opposite order) make sense, depending on effort

@denrase
Copy link
Collaborator

denrase commented Mar 5, 2025

memorySize: device?.memorySize ?? platformMemory.getTotalPhysicalMemory(),
freeMemory: device?.freeMemory ?? platformMemory.getFreePhysicalMemory(),

Total is easy, only need to cache once.

@denrase
Copy link
Collaborator

denrase commented Mar 5, 2025

Ok, the command we are using on windows was deprecated and is not part of the system per default.

https://learn.microsoft.com/en-us/windows/win32/wmisdk/wmic

So we always call the process and get null for the value. Checking if there is an alternative.

@denrase
Copy link
Collaborator

denrase commented Mar 5, 2025

From the repo we got the code from in question: onepub-dev/system_info#12

@denrase
Copy link
Collaborator

denrase commented Mar 5, 2025

Tested a version where we use powershell instead, as this is present on newer systems, but it is even slower than before. Come tho think of it, we see a large slowdown now, even when the call fails, so it might be even slower on systems that have wmic installed.

So i think the most reasonable approach would be to just fetch physical memory once and disable free memory fetching from windows or cache it for a longer time, until we can come up with a better approach.

Image

@denrase
Copy link
Collaborator

denrase commented Mar 5, 2025

@Knupper Would you be so kind and give us feedback for the fix/workaround? You can test it with a dependency override:

dependency_overrides:
  sentry_flutter:
    git:
      url: [email protected]:getsentry/sentry-dart.git
      ref: fix/windows-paltform-memory

@kahest
Copy link
Member

kahest commented Mar 5, 2025

@denrase IIUC the test runs 20 calls and the overhead of fetching memory info is ~3.3s, so one call takes ~167ms? that's awful 😅

I see GlobalMemoryStatusEx recommended and the win32 package also uses it - maybe a better alternative? not worth it adding win32 as dependency I think though

@kahest kahest moved this from Needs Discussion to In Investigation in Mobile SDKs Mar 5, 2025
@denrase
Copy link
Collaborator

denrase commented Mar 5, 2025

@kahest Not quite, i update the sample to run more calls, but still significant when it should be close to no overhead.

@denrase denrase moved this from In Investigation to Needs Review in Mobile SDKs Mar 5, 2025
@Knupper
Copy link
Author

Knupper commented Mar 5, 2025

@denrase i was not able to override the dependency directly, as i get the following error:

Could not find a file named "pubspec.yaml" in [email protected]:getsentry/sentry-dart.git 4211fff06ae5a7d3b48dbc2d8dfa222c95435bd8.

then i cloned your repository and checkout your pull request branch and adjust the dependency override to go to the local version.

then i was able to run it, but the performance was not better. as well i tried to implement the fix inside our main app, and there was no performance improvement as well.

@getsantry getsantry bot moved this to Waiting for: Product Owner in GitHub Issues with 👀 3 Mar 5, 2025
@getsantry getsantry bot removed the status in GitHub Issues with 👀 3 Mar 6, 2025
@buenaflor
Copy link
Contributor

@Knupper can you check if this is an issue in older sentry flutter versions as well?

@buenaflor buenaflor moved this from Needs Review to In Progress in Mobile SDKs Mar 11, 2025
@Knupper
Copy link
Author

Knupper commented Mar 11, 2025

@buenaflor with sentry_flutter: 8.0.0 and 8.1.0, 8.2.0, 8.3.0 the calls are much faster, there we have only a 4ms delay. after version 8.4.0 it takes much more time. i hope that helps?

@getsantry getsantry bot moved this to Waiting for: Product Owner in GitHub Issues with 👀 3 Mar 11, 2025
@buenaflor
Copy link
Contributor

Yes, thank you! Helps us narrow it down

@denrase
Copy link
Collaborator

denrase commented Mar 11, 2025

What i found so far:

  • I'm indeed having the overhead even with the provided fix, probably measured wrong.
  • I could not reproduce faster calls with sentry_flutter version < 8.4.0, they have the same overhead.
  • I need to press the buttons multiple times to get reasonable times, even without sentry. It seems to me there is some overhead?
  • These issues could also be a result of my testing environment, as I run a VM with Parallels on a M1 mac.
  • We are using the HttpTransport on Windows.
  • The only way to remove overhead is by disabling http transport, which we can't do.

@denrase
Copy link
Collaborator

denrase commented Mar 11, 2025

Also SentryWidgetsBindingMixin seems to slow down the whole thing.

Image

@buenaflor
Copy link
Contributor

buenaflor commented Mar 11, 2025

Also SentryWidgetsBindingMixin seems to slow down the whole thing.

on desktop the frames tracking is disabled so this shouldn't be an issue there

@buenaflor
Copy link
Contributor

@denrase maybe what's interesting to check is if there is a difference if you use Sentry.init vs SentryFlutter.init

@Knupper
Copy link
Author

Knupper commented Mar 12, 2025

According to your changelog, it could be this change, as before there was no memory usage for windows. So i would agree with you, that it has to do with the memory allocation process. But i think caching is maybe not the best option if there are multiple requests that are startet at the same time, there will no benefit from caching.

Add memory usage to contexts (#2133)
Only for Linux/Windows applications, as iOS/Android/macOS use native SDKs

The main question for me is, why does this async transaction from sentry delays the response from every call? On which time do you read the free memory? on transaction start or on transaction end? Maybe it could be a solution to move it to the finish as this has no impact on fetching the result?

@getsantry getsantry bot moved this to Waiting for: Product Owner in GitHub Issues with 👀 3 Mar 12, 2025
@denrase
Copy link
Collaborator

denrase commented Mar 12, 2025

on desktop the frames tracking is disabled so this shouldn't be an issue there

Yeah since this is an override of build in functionality, I'd assume that this is just the normal system calls to the method.

@denrase
Copy link
Collaborator

denrase commented Mar 12, 2025

According to your changelog, it could be this change, as before there was no memory usage for windows. So i would agree with you, that it has to do with the memory allocation process.

I have now disabled memory collection on Windows/Linux per default. Even with caching, calling an external process even once was slow in my testing.

But i think caching is maybe not the best option if there are multiple requests that are startet at the same time, there will no benefit from caching.

As for caching the platform memory, this is done in a class we hold throughout the lifecycle of the SDK. All transactions we process can access it.

The main question for me is, why does this async transaction from sentry delays the response from every call? On which time do you read the free memory? on transaction start or on transaction end? Maybe it could be a solution to move it to the finish as this has no impact on fetching the result?

We do processing/enriching of transactions after they are finished. Afterwards we send them to sentry.

@Knupper would you be so kind and you try out how the performance impact is now with memory collection disabled by default? I can only test in a virtual machine, which is not really representative. 🙇

@Knupper
Copy link
Author

Knupper commented Mar 13, 2025

@denrase i was not able to test it with the performance app, as i get compile errors there. as i get following error:

../../../sentry-dart-main/flutter/lib/src/event_processor/flutter_enricher_event_processor.dart:47:14: Error: The setter 'runtimes' isn't defined for the class 'Contexts'.

  • 'Contexts' is from 'package:sentry/src/protocol/contexts.dart' ('../../../../AppData/Local/Pub/Cache/hosted/pub.dev/sentry-8.14.0/lib/src/protocol/contexts.dart').
    Try correcting the name to the name of an existing setter, or defining a setter or field named 'runtimes'.
    contexts.runtimes = _getRuntimes(contexts.runtimes);
    ^^^^^^^^

i have checked out your branch and overrides it to my local version

dependency_overrides:
sentry_flutter:
path: ../../../sentry-dart-main/flutter

@denrase
Copy link
Collaborator

denrase commented Mar 17, 2025

We have created a new PR where we remove free platform memory for now. #2798

@buenaflor
Copy link
Contributor

buenaflor commented Mar 18, 2025

We will release the fix soon in 8.14.1

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
Status: No status
Status: In Progress
Development

No branches or pull requests

4 participants