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

O11Y-1504: wo11y-dart tracer.trace spans don't end until the parent span ends #41

Merged
merged 7 commits into from
Mar 11, 2022

Conversation

michaelyeager-wf
Copy link
Contributor

Notes

This PR follows the example of Dart's IO methods (for example, the File class), splitting the former method into traceSync and traceAsync variants so that the purpose of each method is more clear and so that consumers can choose the execution method which best suits their code.

Recommended Reading

Dart Documentation: Incorrectly Using An Asynchronous Function

The Underlying Bug

The former trace utility method did not operate properly when called in a synchronous manner.

As described in the ticket for this issue, the reporter was using trace in the following way:

for (var element in elements) {
        count++;
        tracer.trace('_notifySelectionBoundsChanged inner', () {
          print('>>> _notifySelectionBoundsChanged element');
          if (left == null || element.bounds.left < left) {
            left = element.bounds.left;
          }
          if (right == null || element.bounds.right > right) {
            right = element.bounds.right;
          }
        }); // Tracer.trace end
      }

and seeing the following results:
image

The implementation of trace was asynchronous. In Dart, calling asynchronous code in an synchronous manner will cause a Future to be returned, which is scheduled and run at some time in the future. Since trace was called in a loop, this had the effect of scheduling many Futures to run at once, each of which started a span and waited for their attached function to execute. Since Dart is not multi-threaded, this blocking caused the "wedge"-shaped execution order seen above.

This PR prevents this situation by providing methods for correctly tracing each style of code and being more explicit about which should be used. Tests have also been created to replicate the failure situation in order to prevent regression in future.

Reviewers

@evanweible-wf
@Workiva/product-new-relic

@rmconsole-wf
Copy link

rmconsole-wf commented Mar 4, 2022

Merge Requirements Met ✅

Request Rosie to automerge this pull request by including @Workiva/release-management-p in a comment.

General Information

Ticket(s):

Code Review(s): #41
Release Image Tags:

Reviewers: michaelyeager-wf, blakeroberts-wk

Additional Information

Watchlist Notifications: None
Pull Requests included in release:

	When this pull is merged I will add it to the following release:
	Current version: opentelemetry-dart 0.2.0
	Version after merge: opentelemetry-dart 1.0.0
	Release Ticket(s): O11Y-1576

	This pull is considered a release pull
	The options defined for this repo will be carried out


Note: This is a shortened report. Click here to view Rosie's full evaluation.
Last updated on Friday, March 11 05:02 PM CST

@michaelyeager-wf
Copy link
Contributor Author

I am confident that the unit tests added in this PR cover testing of this code. However, I will load this into our test app and attach NR links from some final verification. Please feel free to continue review in the mean time.

@aviary2-wf
Copy link

Security Insights

No security relevant content was detected by automated scans.

Action Items

  • Review PR for security impact; comment "security review required" if needed or unsure
  • Verify aviary.yaml coverage of security relevant code

Questions or Comments? Reach out on Slack: #support-infosec.

@semveraudit-wf
Copy link

semveraudit-wf commented Mar 4, 2022

Public API Changes

Recommendation: ‼️ Major version bump (fyi @Workiva/semver-audit-group )

@@ line 11: package:opentelemetry/src/api/trace/span.dart @@
abstract class Span
+     void recordException(dynamic exception, {StackTrace stackTrace})
//    Adding abstract members breaks all subclasses.
@@ line 7: package:opentelemetry/src/api/trace/tracer.dart @@
abstract class Tracer
+     FutureOr<R> trace<R>(String name, FutureOr<R> Function() fn, {Context context})
//    Adding abstract members breaks all subclasses.
@@ line 12: package:opentelemetry/src/api/trace/nonrecording_span.dart @@
class NonRecordingSpan implements Span
+     void recordException(dynamic exception, {StackTrace stackTrace})
//    Adding a method is a minor change.
@@ line 6: package:opentelemetry/src/sdk/trace/span.dart @@
class Span implements Span
+     void recordException(dynamic exception, {StackTrace stackTrace})
//    Adding a method is a minor change.

Showing results for f482ad1

Powered by semver-audit-service. Please report any problems by filing an issue.
Reported by the dart semver audit client 2.2.2
Browse public API.

Last edited UTC Mar 11 at 22:37:30

lib/src/sdk/trace/tracer.dart Outdated Show resolved Hide resolved
lib/src/sdk/trace/tracer.dart Outdated Show resolved Hide resolved
lib/src/sdk/trace/tracer.dart Outdated Show resolved Hide resolved
…pan ends

 - Added trace utility methods to API to enable access to outside
   consumers.
@michaelyeager-wf
Copy link
Contributor Author

QA +1

…pan ends

 - Added implementation to NoopTracer.
@@ -53,27 +53,48 @@ class Tracer implements api.Tracer {
attributes: attributes);
}

/// Records a span of the given [name] for the given function and marks the
/// span as errored if an exception occurs.
FutureOr<R> trace<R>(String name, FutureOr<R> Function() fn,
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Curious, in what case does it make sense to use FutureOr? Based on this bug and our solution, it seems FutureOr itself should never be used.

Unless, perhaps it would be possible to use this same api definition, but have two distinct (private) implementations where this method inspects whether or not fn is async or not, and calls the appropriate async/sync private implementation of trace().

I'm not saying we should do it this way, just wondering if that is possible, and in general, how the type FutureOr should be used.

Copy link
Contributor Author

@michaelyeager-wf michaelyeager-wf Mar 7, 2022

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm eager to learn more in this area too. The documentation for FutureOr makes it sound very quasai-internal and good, concrete examples are difficult to locate.
Like you, I'm not sure it's the best fit here either because I try to avoid explicit type-checking if I can help it and since Zones are involved the code is easier to get wrong than it would be otherwise.

@evanweible-wf, could you help us understand when we should be looking to use FutureOr, and/or the kinds of problems its best at solving?

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

iirc, FutureOr was added in Dart 2 to help simplify how they implement async APIs and to reduce future-chaining, because it allows them to return a value directly from an async function without having to wrap it in a future. So it's definitely not necessary to use it, but it does have some interesting applications in that it can often combine async/sync into a single API.

I actually just realized that it wouldn't be that hard to write and we don't need Error.throwWithStackTrace - the following works and all of the tests in this branch pass with it:

  @override
  FutureOr<R> trace<R>(String name, FutureOr<R> Function() fn,
      {api.Context context}) async {
    context ??= api.Context.current;
    final span = startSpan(name, context: context);

    FutureOr<R> result;
    try {
      result = context.withSpan(span).execute(fn);
      if (result is Future) {
        result = await result;
      }
      return result;
    } catch (e, s) {
      span.recordException(e, stackTrace: s);
      rethrow;
    } finally {
      span.end();
    }
  }

Obviously the crux of it is:

result = context.withSpan(span).execute(fn);
if (result is Future) {
  result = await result;
}

Since the function can return R or Future<R>, we just need to check if the returned value is a future and await it if so. All of that happens within the try/catch, so exceptions are handled as expected in either case.

Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Nice. I like this a lot. I think it's succinct and one less api method to worry about in terms of both maintenance and consumption

Copy link
Contributor Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I agree, this is really slick. Thanks!

…pan ends

 - Consolidated code for attaching error metadata to spans.
 - Added code comments to clarify operation of async tracer utility.
lib/src/api/trace/nonrecording_span.dart Outdated Show resolved Hide resolved
@@ -53,27 +53,48 @@ class Tracer implements api.Tracer {
attributes: attributes);
}

/// Records a span of the given [name] for the given function and marks the
/// span as errored if an exception occurs.
FutureOr<R> trace<R>(String name, FutureOr<R> Function() fn,
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

iirc, FutureOr was added in Dart 2 to help simplify how they implement async APIs and to reduce future-chaining, because it allows them to return a value directly from an async function without having to wrap it in a future. So it's definitely not necessary to use it, but it does have some interesting applications in that it can often combine async/sync into a single API.

I actually just realized that it wouldn't be that hard to write and we don't need Error.throwWithStackTrace - the following works and all of the tests in this branch pass with it:

  @override
  FutureOr<R> trace<R>(String name, FutureOr<R> Function() fn,
      {api.Context context}) async {
    context ??= api.Context.current;
    final span = startSpan(name, context: context);

    FutureOr<R> result;
    try {
      result = context.withSpan(span).execute(fn);
      if (result is Future) {
        result = await result;
      }
      return result;
    } catch (e, s) {
      span.recordException(e, stackTrace: s);
      rethrow;
    } finally {
      span.end();
    }
  }

Obviously the crux of it is:

result = context.withSpan(span).execute(fn);
if (result is Future) {
  result = await result;
}

Since the function can return R or Future<R>, we just need to check if the returned value is a future and await it if so. All of that happens within the try/catch, so exceptions are handled as expected in either case.

Michael Yeager added 2 commits March 8, 2022 13:40
…pan ends

 - Removed span duration verification from tracer utility integration
   tests.
@michaelyeager-wf
Copy link
Contributor Author

@Workiva/release-management-p

@rmconsole-wf
Copy link

@michaelyeager-wf I will not merge this because:

  • 'Semver signoff applied on latest commit of major change' is False

evanweible-wf
evanweible-wf previously approved these changes Mar 11, 2022
lib/src/sdk/trace/tracer.dart Outdated Show resolved Hide resolved
@evanweible-wf
Copy link
Contributor

FYI semver-audit is recommending a major change because of the addition to the interface, but since you control all the implementations so far, it can be downgraded to a minor. You'll just need to change the semver label on the PR

…pan ends

 - Minor corrections in documentation.
@blakeroberts-wk
Copy link
Contributor

semver +1

Copy link

@rmconsole-wf rmconsole-wf left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

+1 from RM

@rmconsole-wf
Copy link

Could not merge pull request. For assistance, reach out to a member of Release Management in the '#support-release' Slack channel

Error: Required status check 'Aviary' is pending.

@rmconsole2-wf rmconsole2-wf merged commit 1bfafc2 into Workiva:master Mar 11, 2022
@rmconsole2-wf rmconsole2-wf deleted the myeager-wf/O11Y-1504 branch March 11, 2022 23:02
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Projects
None yet
Development

Successfully merging this pull request may close these issues.

7 participants