@@ -11,12 +11,18 @@ const getPort = require('get-port')
1111const dc = require ( 'dc-polyfill' )
1212const plugin = require ( '../src' )
1313
14+ const { performance } = require ( 'perf_hooks' )
15+
1416describe ( 'Plugin' , ( ) => {
1517 let tracer
1618 let graphql
1719 let schema
1820 let sort
1921
22+ let markFast
23+ let markSlow
24+ let markSync
25+
2026 function buildSchema ( ) {
2127 const Human = new graphql . GraphQLObjectType ( {
2228 name : 'Human' ,
@@ -80,6 +86,31 @@ describe('Plugin', () => {
8086 resolve ( obj , args ) {
8187 return [ { } , { } , { } ]
8288 }
89+ } ,
90+ fastAsyncField : {
91+ type : graphql . GraphQLString ,
92+ resolve ( obj , args ) {
93+ return new Promise ( ( resolve ) => {
94+ markFast = performance . now ( )
95+ resolve ( 'fast field' )
96+ } )
97+ }
98+ } ,
99+ slowAsyncField : {
100+ type : graphql . GraphQLString ,
101+ resolve ( obj , args ) {
102+ return new Promise ( ( resolve ) => {
103+ markSlow = performance . now ( )
104+ resolve ( 'slow field' )
105+ } )
106+ }
107+ } ,
108+ syncField : {
109+ type : graphql . GraphQLString ,
110+ resolve ( obj , args ) {
111+ markSync = performance . now ( )
112+ return 'sync field'
113+ }
83114 }
84115 }
85116 } )
@@ -380,6 +411,73 @@ describe('Plugin', () => {
380411 graphql . graphql ( { schema, source } ) . catch ( done )
381412 } )
382413
414+ it ( 'should instrument each field resolver duration independently' , done => {
415+ const source = `
416+ {
417+ human {
418+ fastAsyncField
419+ slowAsyncField
420+ syncField
421+ }
422+ }
423+ `
424+
425+ let foundFastFieldSpan = false
426+ let foundSlowFieldSpan = false
427+ let foundSyncFieldSpan = false
428+
429+ let fastAsyncTime
430+ let slowAsyncTime
431+ let syncTime
432+
433+ const processTraces = ( traces ) => {
434+ try {
435+ for ( const trace of traces ) {
436+ for ( const span of trace ) {
437+ if ( span . name !== 'graphql.resolve' ) {
438+ continue
439+ }
440+
441+ if ( span . resource === 'fastAsyncField:String' ) {
442+ expect ( fastAsyncTime ) . to . be . lessThan ( slowAsyncTime )
443+ foundFastFieldSpan = true
444+ } else if ( span . resource === 'slowAsyncField:String' ) {
445+ expect ( slowAsyncTime ) . to . be . lessThan ( syncTime )
446+ foundSlowFieldSpan = true
447+ } else if ( span . resource === 'syncField:String' ) {
448+ expect ( syncTime ) . to . be . greaterThan ( slowAsyncTime )
449+ foundSyncFieldSpan = true
450+ }
451+
452+ if ( foundFastFieldSpan && foundSlowFieldSpan && foundSyncFieldSpan ) {
453+ agent . unsubscribe ( processTraces )
454+ done ( )
455+ return
456+ }
457+ }
458+ }
459+ } catch ( e ) {
460+ agent . unsubscribe ( processTraces )
461+ done ( e )
462+ }
463+ }
464+
465+ agent . subscribe ( processTraces )
466+
467+ const markStart = performance . now ( )
468+
469+ graphql . graphql ( { schema, source } )
470+ . then ( ( result ) => {
471+ fastAsyncTime = markFast - markStart
472+ slowAsyncTime = markSlow - markStart
473+ syncTime = markSync - markStart
474+ } )
475+ . catch ( ( e ) => {
476+ agent . unsubscribe ( processTraces )
477+ done ( e )
478+ } )
479+ } )
480+
383481 it ( 'should instrument nested field resolvers' , done => {
384482 const source = `
385483 {
0 commit comments