Wrong current observation is set during DataFetcher execution

[mareksvatos]

Hi I’m trying out Micrometer Tracing with Spring GraphQL.

Schema:

type Query{
    playlists: [Playlist]
}

type Playlist {
    id: ID!
    name: String!
    tracks: [Track]
    artists: [Artist]
}

type Track{
    id :ID!
    name: String!
    year: Int!
    artists: [Artist]
}

type Artist{
    id: ID!
    name: String!
}

Schema mappings:

   @QueryMapping
   public List<Playlist> playlists() {
       return playlistService.getAll();
   }

   @BatchMapping(typeName = "Playlist", field = "artists")
   public Map<Playlist, List<Artist>> playlistArtists(final List<Playlist> playlists) {
       return artistService.getArtistsForPlaylists(playlists);
   }

   @BatchMapping(typeName = "Playlist", field = "tracks")
   public Map<Playlist, List<Track>> playlistTracks(final List<Playlist> playlists) {
       return tracksService.getTracks(playlists);
   }

   @BatchMapping(typeName = "Track", field = "artists")
   public Map<Track, List<Artist>> trackArtists(final List<Track> tracks) {
       return artistService.getArtistsForTracks(tracks);
   }

TrackService calls remote service via REST(Spring Cloud Feign)

ArtistService calls remote service via GRPC

Spans with calls to remote services are children of ‘graphql query’ span but they fetch data for tracks and artists fields. I would expect some correlation between the field span and batched request.

If I use @SchemaMapping instead of @BatchMapping and fetch tracks for each playlist individually the span which calls to trackService is still only child of ‘graphql field playlists’ and not ‘graphql field tracks’, which is kind of confusing to me.

Trace with BatchMapping:

Trace with SchemaMapping:

Could you please clarify if this is intended behaviour? Thank you.

[bclozel]

Thanks for the report @mareksvatos!

Indeed, while reviewing the observability instrumentation I found that the current observation was properly set on the way out (in the local context of a DataFetcherResult) but not in the DataFetchingEnvironment instance given to the DataFetcher. This means that the propagation of observation would often skip a level and refer to the parent one instead of the current one, as you've noticed.

I'll revisit the instrumentation to fix this problem.