From ae3de4317574f3ce3375e711d9237f6fc686cccb Mon Sep 17 00:00:00 2001 From: Kyri Petrou Date: Fri, 22 Dec 2023 17:09:01 +1100 Subject: [PATCH 1/4] Optimize tracing field wrappers --- core/src/main/scala/caliban/GraphQL.scala | 5 +- .../main/scala/caliban/InternalUtils.scala | 25 ++++ .../scala/caliban/execution/Executor.scala | 10 +- .../caliban/introspection/adt/__Type.scala | 3 + .../main/scala/caliban/parsing/Parser.scala | 5 +- .../main/scala/caliban/schema/Schema.scala | 31 +++-- .../scala/caliban/validation/Validator.scala | 7 +- .../caliban/wrappers/ApolloTracing.scala | 120 ++++++++++-------- .../scala/caliban/wrappers/FieldMetrics.scala | 53 ++++---- .../main/scala/caliban/wrappers/Wrapper.scala | 8 +- .../tracing/ApolloFederatedTracing.scala | 101 ++++++++------- 11 files changed, 221 insertions(+), 147 deletions(-) create mode 100644 core/src/main/scala/caliban/InternalUtils.scala diff --git a/core/src/main/scala/caliban/GraphQL.scala b/core/src/main/scala/caliban/GraphQL.scala index d888b5f84b..ebc167bc28 100644 --- a/core/src/main/scala/caliban/GraphQL.scala +++ b/core/src/main/scala/caliban/GraphQL.scala @@ -13,6 +13,7 @@ import caliban.schema._ import caliban.validation.Validator import caliban.wrappers.Wrapper import caliban.wrappers.Wrapper._ +import zio.stacktracer.TracingImplicits.disableAutoTrace import zio.{ IO, Trace, URIO, ZIO } /** @@ -87,7 +88,9 @@ trait GraphQL[-R] { self => _ <- Validator.validate(document, typeToValidate) } yield () - private def checkHttpMethod(cfg: ExecutionConfiguration)(req: ExecutionRequest): IO[ValidationError, Unit] = + private def checkHttpMethod(cfg: ExecutionConfiguration)(req: ExecutionRequest)(implicit + trace: Trace + ): IO[ValidationError, Unit] = ZIO .when(req.operationType == OperationType.Mutation && !cfg.allowMutationsOverGetRequests) { HttpRequestMethod.get.flatMap { diff --git a/core/src/main/scala/caliban/InternalUtils.scala b/core/src/main/scala/caliban/InternalUtils.scala new file mode 100644 index 0000000000..cf35256015 --- /dev/null +++ b/core/src/main/scala/caliban/InternalUtils.scala @@ -0,0 +1,25 @@ +package caliban + +import zio.{ UIO, ZIO } + +import java.util.concurrent.atomic.AtomicReference + +private[caliban] object InternalUtils { + + def newAtomicRef[A](a: A): UIO[AtomicReference[A]] = ZIO.succeed(new AtomicReference(a)) + + object syntax { + implicit class AtomicRefOps[A](private val ref: AtomicReference[A]) extends AnyVal { + def update(f: A => A): Unit = { + var loop = true + var next: A = null.asInstanceOf[A] + while (loop) { + val current = ref.get + next = f(current) + loop = !ref.compareAndSet(current, next) + } + () + } + } + } +} diff --git a/core/src/main/scala/caliban/execution/Executor.scala b/core/src/main/scala/caliban/execution/Executor.scala index eb58702958..0449a83614 100644 --- a/core/src/main/scala/caliban/execution/Executor.scala +++ b/core/src/main/scala/caliban/execution/Executor.scala @@ -12,6 +12,7 @@ import caliban.schema.{ ReducedStep, Step, Types } import caliban.wrappers.Wrapper.FieldWrapper import zio._ import zio.query._ +import zio.stacktracer.TracingImplicits.disableAutoTrace import zio.stream.ZStream import scala.annotation.tailrec @@ -210,9 +211,10 @@ object Executor { var remainingNames = names while (remainingResponses ne Nil) { val name = remainingNames.head - val resp = remainingResponses.head match { - case null => i -= 1; fromQueries(i) - case resp => resp + var resp = remainingResponses.head + if (resp eq null) { + i -= 1 + resp = fromQueries(i) } results = (name, resp) :: results remainingResponses = remainingResponses.tail @@ -338,7 +340,7 @@ object Executor { } yield response } - private[caliban] def fail(error: CalibanError): UIO[GraphQLResponse[CalibanError]] = + private[caliban] def fail(error: CalibanError)(implicit trace: Trace): UIO[GraphQLResponse[CalibanError]] = ZIO.succeed(GraphQLResponse(NullValue, List(error))) private[caliban] def mergeFields(field: Field, typeName: String): List[Field] = { diff --git a/core/src/main/scala/caliban/introspection/adt/__Type.scala b/core/src/main/scala/caliban/introspection/adt/__Type.scala index 0ef41bbfbb..32a4b17bb5 100644 --- a/core/src/main/scala/caliban/introspection/adt/__Type.scala +++ b/core/src/main/scala/caliban/introspection/adt/__Type.scala @@ -5,6 +5,7 @@ import caliban.parsing.adt.Definition.TypeSystemDefinition.TypeDefinition import caliban.parsing.adt.Definition.TypeSystemDefinition.TypeDefinition._ import caliban.parsing.adt.Type.{ ListType, NamedType } import caliban.parsing.adt.{ Directive, Type } +import caliban.rendering.DocumentRenderer import caliban.schema.Annotations.GQLExcluded import caliban.schema.Types @@ -24,6 +25,8 @@ case class __Type( ) { self => final override lazy val hashCode: Int = super.hashCode() + private[caliban] lazy val typeNameRepr: String = DocumentRenderer.renderTypeName(this) + def |+|(that: __Type): __Type = __Type( kind, (name ++ that.name).reduceOption((_, b) => b), diff --git a/core/src/main/scala/caliban/parsing/Parser.scala b/core/src/main/scala/caliban/parsing/Parser.scala index 4b0d9ea2a6..7f5b6cfb6d 100644 --- a/core/src/main/scala/caliban/parsing/Parser.scala +++ b/core/src/main/scala/caliban/parsing/Parser.scala @@ -4,7 +4,8 @@ import caliban.CalibanError.ParsingError import caliban.InputValue import caliban.parsing.adt._ import fastparse._ -import zio.{ IO, ZIO } +import zio.stacktracer.TracingImplicits.disableAutoTrace +import zio.{ IO, Trace, ZIO } import scala.util.Try @@ -14,7 +15,7 @@ object Parser { /** * Parses the given string into a [[caliban.parsing.adt.Document]] object or fails with a [[caliban.CalibanError.ParsingError]]. */ - def parseQuery(query: String): IO[ParsingError, Document] = { + def parseQuery(query: String)(implicit trace: Trace): IO[ParsingError, Document] = { val sm = SourceMapper(query) ZIO .attempt(parse(query, document(_))) diff --git a/core/src/main/scala/caliban/schema/Schema.scala b/core/src/main/scala/caliban/schema/Schema.scala index 1ce037470a..e4dcc13148 100644 --- a/core/src/main/scala/caliban/schema/Schema.scala +++ b/core/src/main/scala/caliban/schema/Schema.scala @@ -13,7 +13,8 @@ import caliban.uploads.Upload import caliban.{ InputValue, ResponseValue } import zio.query.ZQuery import zio.stream.ZStream -import zio.{ Chunk, URIO, ZIO } +import zio.{ Chunk, Trace, URIO, ZIO } +import zio.stacktracer.TracingImplicits.disableAutoTrace import java.time._ import java.time.format.DateTimeFormatter @@ -488,12 +489,14 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { } implicit def futureSchema[R0, A](implicit ev: Schema[R0, A]): Schema[R0, Future[A]] = - effectSchema[R0, R0, R0, Throwable, A].contramap[Future[A]](future => ZIO.fromFuture(_ => future)) + effectSchema[R0, R0, R0, Throwable, A].contramap[Future[A]](future => ZIO.fromFuture(_ => future)(Trace.empty)) implicit def infallibleEffectSchema[R0, R1 >: R0, R2 >: R0, A](implicit ev: Schema[R2, A]): Schema[R0, URIO[R1, A]] = new Schema[R0, URIO[R1, A]] { override def optional: Boolean = ev.optional override def toType(isInput: Boolean, isSubscription: Boolean): __Type = ev.toType_(isInput, isSubscription) - override def resolve(value: URIO[R1, A]): Step[R0] = QueryStep(ZQuery.fromZIO(value.map(ev.resolve))) + override def resolve(value: URIO[R1, A]): Step[R0] = QueryStep( + ZQuery.fromZIO(value.map(ev.resolve)(Trace.empty))(Trace.empty) + ) } implicit def effectSchema[R0, R1 >: R0, R2 >: R0, E <: Throwable, A](implicit ev: Schema[R2, A] @@ -501,7 +504,9 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { new Schema[R0, ZIO[R1, E, A]] { override def optional: Boolean = true override def toType(isInput: Boolean, isSubscription: Boolean): __Type = ev.toType_(isInput, isSubscription) - override def resolve(value: ZIO[R1, E, A]): Step[R0] = QueryStep(ZQuery.fromZIO(value.map(ev.resolve))) + override def resolve(value: ZIO[R1, E, A]): Step[R0] = QueryStep( + ZQuery.fromZIO(value.map(ev.resolve)(Trace.empty))(Trace.empty) + ) } def customErrorEffectSchema[R0, R1 >: R0, R2 >: R0, E, A](convertError: E => ExecutionError)(implicit ev: Schema[R2, A] @@ -510,7 +515,7 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { override def optional: Boolean = true override def toType(isInput: Boolean, isSubscription: Boolean): __Type = ev.toType_(isInput, isSubscription) override def resolve(value: ZIO[R1, E, A]): Step[R0] = QueryStep( - ZQuery.fromZIO(value.mapBoth(convertError, ev.resolve)) + ZQuery.fromZIO(value.mapBoth(convertError, ev.resolve)(implicitly, Trace.empty))(Trace.empty) ) } implicit def infallibleQuerySchema[R0, R1 >: R0, R2 >: R0, A](implicit @@ -519,7 +524,7 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { new Schema[R0, ZQuery[R1, Nothing, A]] { override def optional: Boolean = ev.optional override def toType(isInput: Boolean, isSubscription: Boolean): __Type = ev.toType_(isInput, isSubscription) - override def resolve(value: ZQuery[R1, Nothing, A]): Step[R0] = QueryStep(value.map(ev.resolve)) + override def resolve(value: ZQuery[R1, Nothing, A]): Step[R0] = QueryStep(value.map(ev.resolve)(Trace.empty)) } implicit def querySchema[R0, R1 >: R0, R2 >: R0, E <: Throwable, A](implicit ev: Schema[R2, A] @@ -527,7 +532,7 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { new Schema[R0, ZQuery[R1, E, A]] { override def optional: Boolean = true override def toType(isInput: Boolean, isSubscription: Boolean): __Type = ev.toType_(isInput, isSubscription) - override def resolve(value: ZQuery[R1, E, A]): Step[R0] = QueryStep(value.map(ev.resolve)) + override def resolve(value: ZQuery[R1, E, A]): Step[R0] = QueryStep(value.map(ev.resolve)(Trace.empty)) } def customErrorQuerySchema[R0, R1 >: R0, R2 >: R0, E, A](convertError: E => ExecutionError)(implicit ev: Schema[R2, A] @@ -535,7 +540,9 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { new Schema[R0, ZQuery[R1, E, A]] { override def optional: Boolean = true override def toType(isInput: Boolean, isSubscription: Boolean): __Type = ev.toType_(isInput, isSubscription) - override def resolve(value: ZQuery[R1, E, A]): Step[R0] = QueryStep(value.mapBoth(convertError, ev.resolve)) + override def resolve(value: ZQuery[R1, E, A]): Step[R0] = QueryStep( + value.mapBoth(convertError, ev.resolve)(implicitly, Trace.empty) + ) } implicit def infallibleStreamSchema[R1, R2 >: R1, A](implicit ev: Schema[R2, A] @@ -546,7 +553,7 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { val t = ev.toType_(isInput, isSubscription) if (isSubscription) t else (if (ev.optional) t else t.nonNull).list } - override def resolve(value: ZStream[R1, Nothing, A]): Step[R1] = StreamStep(value.map(ev.resolve)) + override def resolve(value: ZStream[R1, Nothing, A]): Step[R1] = StreamStep(value.map(ev.resolve)(Trace.empty)) } implicit def streamSchema[R0, R1 >: R0, R2 >: R0, E <: Throwable, A](implicit ev: Schema[R2, A] @@ -557,7 +564,7 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { val t = ev.toType_(isInput, isSubscription) if (isSubscription) t else (if (ev.optional) t else t.nonNull).list } - override def resolve(value: ZStream[R1, E, A]): Step[R0] = StreamStep(value.map(ev.resolve)) + override def resolve(value: ZStream[R1, E, A]): Step[R0] = StreamStep(value.map(ev.resolve)(Trace.empty)) } def customErrorStreamSchema[R0, R1 >: R0, R2 >: R0, E, A](convertError: E => ExecutionError)(implicit ev: Schema[R2, A] @@ -568,7 +575,9 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { val t = ev.toType_(isInput, isSubscription) if (isSubscription) t else (if (ev.optional) t else t.nonNull).list } - override def resolve(value: ZStream[R1, E, A]): Step[R0] = StreamStep(value.mapBoth(convertError, ev.resolve)) + override def resolve(value: ZStream[R1, E, A]): Step[R0] = StreamStep( + value.mapBoth(convertError, ev.resolve)(implicitly, Trace.empty) + ) } } diff --git a/core/src/main/scala/caliban/validation/Validator.scala b/core/src/main/scala/caliban/validation/Validator.scala index a4d33ba868..05526c045d 100644 --- a/core/src/main/scala/caliban/validation/Validator.scala +++ b/core/src/main/scala/caliban/validation/Validator.scala @@ -21,7 +21,8 @@ import caliban.validation.Utils.isObjectType import caliban.{ Configurator, InputValue } import zio.prelude._ import zio.prelude.fx.ZPure -import zio.{ IO, ZIO } +import zio.stacktracer.TracingImplicits.disableAutoTrace +import zio.{ IO, Trace, ZIO } import scala.annotation.tailrec import scala.collection.mutable @@ -47,13 +48,13 @@ object Validator { /** * Verifies that the given document is valid for this type. Fails with a [[caliban.CalibanError.ValidationError]] otherwise. */ - def validate(document: Document, rootType: RootType): IO[ValidationError, Unit] = + def validate(document: Document, rootType: RootType)(implicit trace: Trace): IO[ValidationError, Unit] = Configurator.configuration.map(_.validations).flatMap(check(document, rootType, Map.empty, _).unit.toZIO) /** * Verifies that the given schema is valid. Fails with a [[caliban.CalibanError.ValidationError]] otherwise. */ - def validateSchema[R](schema: RootSchemaBuilder[R]): IO[ValidationError, RootSchema[R]] = { + def validateSchema[R](schema: RootSchemaBuilder[R])(implicit trace: Trace): IO[ValidationError, RootSchema[R]] = { val schemaValidation = validateSchemaEither(schema) ZIO.fromEither(schemaValidation) } diff --git a/core/src/main/scala/caliban/wrappers/ApolloTracing.scala b/core/src/main/scala/caliban/wrappers/ApolloTracing.scala index d3a619ed96..254defacd7 100644 --- a/core/src/main/scala/caliban/wrappers/ApolloTracing.scala +++ b/core/src/main/scala/caliban/wrappers/ApolloTracing.scala @@ -1,18 +1,19 @@ package caliban.wrappers +import caliban.InternalUtils.syntax._ import caliban.ResponseValue.{ ListValue, ObjectValue } import caliban.Value.{ IntValue, StringValue } import caliban._ import caliban.execution.{ ExecutionRequest, FieldInfo } import caliban.parsing.adt.Document -import caliban.rendering.DocumentRenderer import caliban.wrappers.Wrapper._ import zio._ -import zio.query.{ UQuery, ZQuery } +import zio.query.ZQuery import java.time.format.DateTimeFormatter import java.time.{ Instant, ZoneId } import java.util.concurrent.TimeUnit +import java.util.concurrent.atomic.AtomicReference object ApolloTracing { @@ -34,12 +35,12 @@ object ApolloTracing { ZIO .whenZIO(isEnabledRef.get)( for { - ref <- Ref.make(Tracing()) + ref <- InternalUtils.newAtomicRef(Tracing()) clock <- ZIO.clock } yield apolloTracingOverall(clock, ref) |+| apolloTracingParsing(clock, ref) |+| apolloTracingValidation(clock, ref) |+| - apolloTracingField(ZQuery.fromZIO(clock.nanoTime), ref, !excludePureFields) + Unsafe.unsafe(implicit u => apolloTracingField(clock.unsafe.nanoTime(), ref, !excludePureFields)) ) .someOrElse(Wrapper.empty) ) @@ -58,14 +59,14 @@ object ApolloTracing { .ofPattern("yyyy-MM-dd'T'HH:mm:ss.SSS'Z'") .withZone(ZoneId.of("UTC")) - case class Parsing(startOffset: Long = 0, duration: Duration = Duration.Zero) { + case class Parsing(startOffset: Long = 0, durationNanos: Long = 0L) { def toResponseValue: ResponseValue = - ObjectValue(List("startOffset" -> IntValue(startOffset), "duration" -> IntValue(duration.toNanos))) + ObjectValue(List("startOffset" -> IntValue(startOffset), "duration" -> IntValue(durationNanos))) } - case class Validation(startOffset: Long = 0, duration: Duration = Duration.Zero) { + case class Validation(startOffset: Long = 0, durationNanos: Long = 0L) { def toResponseValue: ResponseValue = - ObjectValue(List("startOffset" -> IntValue(startOffset), "duration" -> IntValue(duration.toNanos))) + ObjectValue(List("startOffset" -> IntValue(startOffset), "duration" -> IntValue(durationNanos))) } case class Resolver( @@ -74,7 +75,7 @@ object ApolloTracing { fieldName: String = "", returnType: String = "", startOffset: Long = 0, - duration: Duration = Duration.Zero + durationNanos: Long = 0 ) { def toResponseValue: ResponseValue = ObjectValue( @@ -84,18 +85,22 @@ object ApolloTracing { "fieldName" -> StringValue(fieldName), "returnType" -> StringValue(returnType), "startOffset" -> IntValue(startOffset), - "duration" -> IntValue(duration.toNanos) + "duration" -> IntValue(durationNanos) ) ) } + object Resolver { + implicit val ordering: Ordering[Resolver] = { (x: Resolver, y: Resolver) => + val ord1 = Ordering.Long.compare(x.startOffset, y.startOffset) + if (ord1 != 0) ord1 + else Ordering.Long.compare(x.durationNanos, y.durationNanos) + } + } + case class Execution(resolvers: List[Resolver] = Nil) { def toResponseValue: ResponseValue = - ObjectValue( - List( - "resolvers" -> ListValue(resolvers.sortBy(r => (r.startOffset, r.duration.toNanos)).map(_.toResponseValue)) - ) - ) + ObjectValue(List("resolvers" -> ListValue(resolvers.sorted.map(_.toResponseValue)))) } case class Tracing( @@ -103,7 +108,7 @@ object ApolloTracing { startTime: Long = 0, endTime: Long = 0, startTimeMonotonic: Long = 0, - duration: Duration = Duration.Zero, + durationNanos: Long = 0L, parsing: Parsing = Parsing(), validation: Validation = Validation(), execution: Execution = Execution() @@ -114,7 +119,7 @@ object ApolloTracing { "version" -> IntValue(version), "startTime" -> StringValue(dateFormatter.format(Instant.ofEpochMilli(startTime))), "endTime" -> StringValue(dateFormatter.format(Instant.ofEpochMilli(endTime))), - "duration" -> IntValue(duration.toNanos), + "duration" -> IntValue(durationNanos), "parsing" -> parsing.toResponseValue, "validation" -> validation.toResponseValue, "execution" -> execution.toResponseValue @@ -122,7 +127,7 @@ object ApolloTracing { ) } - private def apolloTracingOverall(clock: Clock, ref: Ref[Tracing]): OverallWrapper[Any] = + private def apolloTracingOverall(clock: Clock, ref: AtomicReference[Tracing]): OverallWrapper[Any] = new OverallWrapper[Any] { def wrap[R1]( process: GraphQLRequest => ZIO[R1, Nothing, GraphQLResponse[CalibanError]] @@ -131,12 +136,11 @@ object ApolloTracing { for { nanoTime <- clock.nanoTime currentTime <- clock.currentTime(TimeUnit.MILLISECONDS) - _ <- ref.update(_.copy(startTime = currentTime, startTimeMonotonic = nanoTime)) + _ <- ZIO.succeed(ref.update(_.copy(startTime = currentTime, startTimeMonotonic = nanoTime))) result <- process(request).timed.flatMap { case (duration, result) => for { endTime <- clock.currentTime(TimeUnit.MILLISECONDS) - _ <- ref.update(_.copy(duration = duration, endTime = endTime)) - tracing <- ref.get + tracing <- ZIO.succeed(ref.get.copy(durationNanos = duration.toNanos, endTime = endTime)) } yield result.copy( extensions = Some( ObjectValue( @@ -149,7 +153,7 @@ object ApolloTracing { } yield result } - private def apolloTracingParsing(clock: Clock, ref: Ref[Tracing]): ParsingWrapper[Any] = + private def apolloTracingParsing(clock: Clock, ref: AtomicReference[Tracing]): ParsingWrapper[Any] = new ParsingWrapper[Any] { def wrap[R1]( process: String => ZIO[R1, CalibanError.ParsingError, Document] @@ -159,15 +163,18 @@ object ApolloTracing { start <- clock.nanoTime resultWithDuration <- process(query).timed (duration, result) = resultWithDuration - _ <- ref.update(state => - state.copy( - parsing = state.parsing.copy(startOffset = start - state.startTimeMonotonic, duration = duration) + _ <- ZIO.succeed( + ref.update(state => + state.copy( + parsing = state.parsing + .copy(startOffset = start - state.startTimeMonotonic, durationNanos = duration.toNanos) + ) ) ) } yield result } - private def apolloTracingValidation(clock: Clock, ref: Ref[Tracing]): ValidationWrapper[Any] = + private def apolloTracingValidation(clock: Clock, ref: AtomicReference[Tracing]): ValidationWrapper[Any] = new ValidationWrapper[Any] { def wrap[R1]( process: Document => ZIO[R1, CalibanError.ValidationError, ExecutionRequest] @@ -177,18 +184,21 @@ object ApolloTracing { start <- clock.nanoTime resultWithDuration <- process(doc).timed (duration, result) = resultWithDuration - _ <- ref.update(state => - state.copy( - validation = - state.validation.copy(startOffset = start - state.startTimeMonotonic, duration = duration) - ) - ) + _ <- + ZIO.succeed( + ref.update(state => + state.copy( + validation = state.validation + .copy(startOffset = start - state.startTimeMonotonic, durationNanos = duration.toNanos) + ) + ) + ) } yield result } private def apolloTracingField( - nanoTime: UQuery[Long], - ref: Ref[Tracing], + nanoTime: => Long, + ref: AtomicReference[Tracing], wrapPureValues: Boolean ): FieldWrapper[Any] = new FieldWrapper[Any](wrapPureValues) { @@ -196,27 +206,27 @@ object ApolloTracing { query: ZQuery[R1, CalibanError.ExecutionError, ResponseValue], fieldInfo: FieldInfo ): ZQuery[R1, CalibanError.ExecutionError, ResponseValue] = - for { - start <- nanoTime - result <- query - end <- nanoTime - _ <- ZQuery.fromZIO( - ref.update(state => - state.copy( - execution = state.execution.copy( - resolvers = Resolver( - path = fieldInfo.path, - parentType = fieldInfo.details.parentType.fold("")(DocumentRenderer.renderTypeName), - fieldName = fieldInfo.name, - returnType = DocumentRenderer.renderTypeName(fieldInfo.details.fieldType), - startOffset = start - state.startTimeMonotonic, - duration = Duration.fromNanos(end - start) - ) :: state.execution.resolvers - ) - ) - ) - ) - } yield result + ZQuery.suspend { + val start = nanoTime + query.map { result => + val end = nanoTime + ref.update(state => + state.copy( + execution = state.execution.copy( + resolvers = Resolver( + path = fieldInfo.path, + parentType = fieldInfo.details.parentType.fold("")(_.typeNameRepr), + fieldName = fieldInfo.name, + returnType = fieldInfo.details.fieldType.typeNameRepr, + startOffset = start - state.startTimeMonotonic, + durationNanos = end - start + ) :: state.execution.resolvers + ) + ) + ) + result + } + } } } diff --git a/core/src/main/scala/caliban/wrappers/FieldMetrics.scala b/core/src/main/scala/caliban/wrappers/FieldMetrics.scala index dfd4d41c5c..17e9f98bc1 100644 --- a/core/src/main/scala/caliban/wrappers/FieldMetrics.scala +++ b/core/src/main/scala/caliban/wrappers/FieldMetrics.scala @@ -1,5 +1,6 @@ package caliban.wrappers +import caliban.InternalUtils.syntax._ import caliban.Value.StringValue import caliban._ import caliban.execution.FieldInfo @@ -7,8 +8,9 @@ import caliban.wrappers.Wrapper.OverallWrapper import zio._ import zio.metrics.MetricKeyType.Histogram import zio.metrics.{ Metric, MetricKey, MetricLabel } -import zio.query.{ UQuery, ZQuery } +import zio.query.ZQuery +import java.util.concurrent.atomic.AtomicReference import scala.jdk.CollectionConverters._ object FieldMetrics { @@ -58,17 +60,17 @@ object FieldMetrics { ): Wrapper.EffectfulWrapper[Any] = Wrapper.EffectfulWrapper( for { - timings <- Ref.make(List.empty[Timing]) - failures <- Ref.make(List.empty[String]) + timings <- InternalUtils.newAtomicRef(List.empty[Timing]) + failures <- InternalUtils.newAtomicRef(List.empty[String]) clock <- ZIO.clock metrics = new Metrics(totalLabel, durationLabel, buckets, extraLabels) } yield overallWrapper(timings, failures, metrics) |+| - fieldWrapper(ZQuery.fromZIO(clock.nanoTime), timings, failures) + Unsafe.unsafe(implicit us => fieldWrapper(clock.unsafe.nanoTime(), timings, failures)) ) private def overallWrapper( - timings: Ref[List[Timing]], - failures: Ref[List[String]], + timings: AtomicReference[List[Timing]], + failures: AtomicReference[List[String]], metrics: Metrics ): OverallWrapper[Any] = new OverallWrapper[Any] { @@ -79,10 +81,10 @@ object FieldMetrics { process(request) <* ZIO .blocking(for { - _ <- failures.get.flatMap(metrics.recordFailures) - timings <- timings.get - nodeOffsets = resolveNodeOffsets(timings) - _ <- metrics.recordSuccesses(nodeOffsets, timings) + _ <- ZIO.suspendSucceed(metrics.recordFailures(failures.get)) + ts <- ZIO.succeed(timings.get) + nodeOffsets = resolveNodeOffsets(ts) + _ <- metrics.recordSuccesses(nodeOffsets, ts) } yield ()) .forkDaemon } @@ -117,9 +119,9 @@ object FieldMetrics { } private def fieldWrapper( - nanoTime: UQuery[Long], - timings: Ref[List[Timing]], - failures: Ref[List[String]] + nanoTime: => Long, + timings: AtomicReference[List[Timing]], + failures: AtomicReference[List[String]] ): Wrapper.FieldWrapper[Any] = new Wrapper.FieldWrapper[Any] { def wrap[R]( @@ -140,15 +142,22 @@ object FieldMetrics { duration = duration ) - def recordFailure(e: CalibanError.ExecutionError) = - ZQuery.fromZIO(failures.update(fieldName :: _) *> ZIO.fail(e)) - - for { - start <- nanoTime - result <- query.catchAll(recordFailure) - end <- nanoTime - _ <- ZQuery.fromZIO(timings.update(makeTiming(end - start) :: _)) - } yield result + ZQuery.suspend { + val st = nanoTime + query.foldQuery( + e => + ZQuery.fail { + failures.update(fieldName :: _) + e + }, + result => + ZQuery.succeed { + val t = makeTiming(nanoTime - st) + timings.update(t :: _) + result + } + ) + } } } diff --git a/core/src/main/scala/caliban/wrappers/Wrapper.scala b/core/src/main/scala/caliban/wrappers/Wrapper.scala index 438565344e..2625abdaf4 100644 --- a/core/src/main/scala/caliban/wrappers/Wrapper.scala +++ b/core/src/main/scala/caliban/wrappers/Wrapper.scala @@ -7,7 +7,8 @@ import caliban.introspection.adt.__Introspection import caliban.parsing.adt.Document import caliban.wrappers.Wrapper.CombinedWrapper import zio.query.ZQuery -import zio.{ UIO, ZIO } +import zio.{ Trace, UIO, ZIO } +import zio.stacktracer.TracingImplicits.disableAutoTrace import scala.annotation.tailrec import scala.collection.mutable.ListBuffer @@ -36,6 +37,9 @@ sealed trait Wrapper[-R] extends GraphQLAspect[Nothing, R] { self => def apply[R1 <: R](that: GraphQL[R1]): GraphQL[R1] = that.withWrapper(self) + + // Disables tracing only for wrappers in the caliban package + final private[caliban] def trace: Trace = Trace.empty } object Wrapper { @@ -147,7 +151,7 @@ object Wrapper { loop(process, wrappers)(info) } - private[caliban] def decompose[R](wrappers: List[Wrapper[R]]): UIO[ + private[caliban] def decompose[R](wrappers: List[Wrapper[R]])(implicit trace: Trace): UIO[ ( List[OverallWrapper[R]], List[ParsingWrapper[R]], diff --git a/federation/src/main/scala/caliban/federation/tracing/ApolloFederatedTracing.scala b/federation/src/main/scala/caliban/federation/tracing/ApolloFederatedTracing.scala index 3c94a441d5..37eb0ec98b 100644 --- a/federation/src/main/scala/caliban/federation/tracing/ApolloFederatedTracing.scala +++ b/federation/src/main/scala/caliban/federation/tracing/ApolloFederatedTracing.scala @@ -1,6 +1,7 @@ package caliban.federation.tracing import caliban.CalibanError.ExecutionError +import caliban.InternalUtils.syntax._ import caliban.ResponseValue.ObjectValue import caliban.Value.{ IntValue, StringValue } import caliban._ @@ -14,6 +15,7 @@ import zio.query.ZQuery import java.util.Base64 import java.util.concurrent.TimeUnit +import java.util.concurrent.atomic.AtomicReference /** * Implements the federated tracing specification detailed here: @@ -29,11 +31,11 @@ object ApolloFederatedTracing { def wrapper(excludePureFields: Boolean = false): EffectfulWrapper[Any] = EffectfulWrapper( for { - tracing <- Ref.make(Tracing(NodeTrie.empty)) - enabled <- Ref.make(false) + tracing <- InternalUtils.newAtomicRef(Tracing(NodeTrie.empty)) + enabled <- InternalUtils.newAtomicRef(false) clock <- ZIO.clock } yield apolloTracingOverall(clock, tracing, enabled) |+| - apolloTracingField(clock, tracing, enabled, !excludePureFields) + Unsafe.unsafe(implicit u => apolloTracingField(clock.unsafe.nanoTime(), tracing, enabled, !excludePureFields)) ) private def toTimestamp(epochMilli: Long): Timestamp = @@ -42,26 +44,32 @@ object ApolloFederatedTracing { (epochMilli % 1000).toInt * 1000000 ) - private def apolloTracingOverall(clock: Clock, ref: Ref[Tracing], enabled: Ref[Boolean]): OverallWrapper[Any] = + private def apolloTracingOverall( + clock: Clock, + ref: AtomicReference[Tracing], + enabled: AtomicReference[Boolean] + ): OverallWrapper[Any] = new OverallWrapper[Any] { def wrap[R1]( process: GraphQLRequest => ZIO[R1, Nothing, GraphQLResponse[CalibanError]] ): GraphQLRequest => ZIO[R1, Nothing, GraphQLResponse[CalibanError]] = (request: GraphQLRequest) => ZIO.ifZIO( - enabled.updateAndGet(_ => - request.extensions.exists( - _.get(GraphQLRequest.`apollo-federation-include-trace`).contains(StringValue(GraphQLRequest.ftv1)) + ZIO.succeed( + enabled.updateAndGet(_ => + request.extensions.exists( + _.get(GraphQLRequest.`apollo-federation-include-trace`).contains(StringValue(GraphQLRequest.ftv1)) + ) ) ) )( for { startNano <- clock.nanoTime - _ <- ref.update(_.copy(startTime = startNano)) + _ <- ZIO.succeed(ref.update(_.copy(startTime = startNano))) response <- process(request).summarized(clock.currentTime(TimeUnit.MILLISECONDS))((_, _)) ((start, end), result) = response endNano <- clock.nanoTime - tracing <- ref.get + tracing <- ZIO.succeed(ref.get) } yield { val root = Trace( startTime = Some(toTimestamp(start)), @@ -85,9 +93,9 @@ object ApolloFederatedTracing { } private def apolloTracingField( - clock: Clock, - ref: Ref[Tracing], - enabled: Ref[Boolean], + nanoTime: => Long, + ref: AtomicReference[Tracing], + enabled: AtomicReference[Boolean], wrapPureValues: Boolean ): FieldWrapper[Any] = new FieldWrapper[Any](wrapPureValues) { @@ -95,41 +103,40 @@ object ApolloFederatedTracing { query: ZQuery[R1, CalibanError.ExecutionError, ResponseValue], fieldInfo: FieldInfo ): ZQuery[R1, CalibanError.ExecutionError, ResponseValue] = - ZQuery - .fromZIO(enabled.get) - .flatMap( - if (_) - for { - response <- query.either.summarized(clock.nanoTime)((_, _)) - ((startTime, endTime), summarized) = response - id = Node.Id.ResponseName(fieldInfo.name) - result <- ZQuery.fromZIO( - ref.update(state => - state.copy( - root = state.root.insert( - (PathValue.Key(fieldInfo.name) :: fieldInfo.path).toVector, - Node( - id = id, - startTime = startTime - state.startTime, - endTime = endTime - state.startTime, - `type` = fieldInfo.details.fieldType.toType().toString, - parentType = fieldInfo.details.parentType.map(_.toType().toString) getOrElse "", - originalFieldName = fieldInfo.details.alias - .map(_ => fieldInfo.details.name) getOrElse "", - error = summarized.left.toOption.collectFirst { case e: ExecutionError => - Error( - e.getMessage(), - location = e.locationInfo.map(l => Location(l.line, l.column)).toSeq - ) - }.toSeq - ) - ) - ) - ) *> ZIO.fromEither(summarized) - ) - } yield result - else query - ) + if (enabled.get()) + ZQuery.suspend { + val startTime = nanoTime + query.either.flatMap { result => + ZQuery.fromEither { + val endTime = nanoTime + val path = (PathValue.Key(fieldInfo.name) :: fieldInfo.path).toVector + ref.update(state => + state.copy( + root = state.root.insert( + path, + Node( + id = Node.Id.ResponseName(fieldInfo.name), + startTime = startTime - state.startTime, + endTime = endTime - state.startTime, + `type` = fieldInfo.details.fieldType.toType().toString, + parentType = fieldInfo.details.parentType.map(_.toType().toString) getOrElse "", + originalFieldName = fieldInfo.details.alias.map(_ => fieldInfo.details.name) getOrElse "", + error = result.left.toOption.collectFirst { case e: ExecutionError => + Error( + e.getMessage(), + location = e.locationInfo.map(l => Location(l.line, l.column)).toSeq + ) + }.toSeq + ) + ) + ) + ) + result + } + } + } + else query + } private type VPath = Vector[PathValue] From fea8b447171c221360bcbecd396f903c23b4c119 Mon Sep 17 00:00:00 2001 From: Kyri Petrou Date: Fri, 22 Dec 2023 17:22:08 +1100 Subject: [PATCH 2/4] Add implicit empty trace to Schema instead --- .../main/scala/caliban/schema/Schema.scala | 31 ++++++++----------- 1 file changed, 13 insertions(+), 18 deletions(-) diff --git a/core/src/main/scala/caliban/schema/Schema.scala b/core/src/main/scala/caliban/schema/Schema.scala index e4dcc13148..85f760f32e 100644 --- a/core/src/main/scala/caliban/schema/Schema.scala +++ b/core/src/main/scala/caliban/schema/Schema.scala @@ -12,9 +12,9 @@ import caliban.schema.Types._ import caliban.uploads.Upload import caliban.{ InputValue, ResponseValue } import zio.query.ZQuery +import zio.stacktracer.TracingImplicits.disableAutoTrace import zio.stream.ZStream import zio.{ Chunk, Trace, URIO, ZIO } -import zio.stacktracer.TracingImplicits.disableAutoTrace import java.time._ import java.time.format.DateTimeFormatter @@ -82,6 +82,9 @@ trait Schema[-R, T] { self => */ def arguments: List[__InputValue] = Nil + // Disables traces for caliban-provided effectful schemas + private[caliban] implicit def trace: Trace = Trace.empty + /** * Builds a new `Schema` of `A` from an existing `Schema` of `T` and a function from `A` to `T`. * @param f a function from `A` to `T`. @@ -494,9 +497,7 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { new Schema[R0, URIO[R1, A]] { override def optional: Boolean = ev.optional override def toType(isInput: Boolean, isSubscription: Boolean): __Type = ev.toType_(isInput, isSubscription) - override def resolve(value: URIO[R1, A]): Step[R0] = QueryStep( - ZQuery.fromZIO(value.map(ev.resolve)(Trace.empty))(Trace.empty) - ) + override def resolve(value: URIO[R1, A]): Step[R0] = QueryStep(ZQuery.fromZIO(value.map(ev.resolve))) } implicit def effectSchema[R0, R1 >: R0, R2 >: R0, E <: Throwable, A](implicit ev: Schema[R2, A] @@ -504,9 +505,7 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { new Schema[R0, ZIO[R1, E, A]] { override def optional: Boolean = true override def toType(isInput: Boolean, isSubscription: Boolean): __Type = ev.toType_(isInput, isSubscription) - override def resolve(value: ZIO[R1, E, A]): Step[R0] = QueryStep( - ZQuery.fromZIO(value.map(ev.resolve)(Trace.empty))(Trace.empty) - ) + override def resolve(value: ZIO[R1, E, A]): Step[R0] = QueryStep(ZQuery.fromZIO(value.map(ev.resolve))) } def customErrorEffectSchema[R0, R1 >: R0, R2 >: R0, E, A](convertError: E => ExecutionError)(implicit ev: Schema[R2, A] @@ -515,7 +514,7 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { override def optional: Boolean = true override def toType(isInput: Boolean, isSubscription: Boolean): __Type = ev.toType_(isInput, isSubscription) override def resolve(value: ZIO[R1, E, A]): Step[R0] = QueryStep( - ZQuery.fromZIO(value.mapBoth(convertError, ev.resolve)(implicitly, Trace.empty))(Trace.empty) + ZQuery.fromZIO(value.mapBoth(convertError, ev.resolve)) ) } implicit def infallibleQuerySchema[R0, R1 >: R0, R2 >: R0, A](implicit @@ -524,7 +523,7 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { new Schema[R0, ZQuery[R1, Nothing, A]] { override def optional: Boolean = ev.optional override def toType(isInput: Boolean, isSubscription: Boolean): __Type = ev.toType_(isInput, isSubscription) - override def resolve(value: ZQuery[R1, Nothing, A]): Step[R0] = QueryStep(value.map(ev.resolve)(Trace.empty)) + override def resolve(value: ZQuery[R1, Nothing, A]): Step[R0] = QueryStep(value.map(ev.resolve)) } implicit def querySchema[R0, R1 >: R0, R2 >: R0, E <: Throwable, A](implicit ev: Schema[R2, A] @@ -532,7 +531,7 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { new Schema[R0, ZQuery[R1, E, A]] { override def optional: Boolean = true override def toType(isInput: Boolean, isSubscription: Boolean): __Type = ev.toType_(isInput, isSubscription) - override def resolve(value: ZQuery[R1, E, A]): Step[R0] = QueryStep(value.map(ev.resolve)(Trace.empty)) + override def resolve(value: ZQuery[R1, E, A]): Step[R0] = QueryStep(value.map(ev.resolve)) } def customErrorQuerySchema[R0, R1 >: R0, R2 >: R0, E, A](convertError: E => ExecutionError)(implicit ev: Schema[R2, A] @@ -540,9 +539,7 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { new Schema[R0, ZQuery[R1, E, A]] { override def optional: Boolean = true override def toType(isInput: Boolean, isSubscription: Boolean): __Type = ev.toType_(isInput, isSubscription) - override def resolve(value: ZQuery[R1, E, A]): Step[R0] = QueryStep( - value.mapBoth(convertError, ev.resolve)(implicitly, Trace.empty) - ) + override def resolve(value: ZQuery[R1, E, A]): Step[R0] = QueryStep(value.mapBoth(convertError, ev.resolve)) } implicit def infallibleStreamSchema[R1, R2 >: R1, A](implicit ev: Schema[R2, A] @@ -553,7 +550,7 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { val t = ev.toType_(isInput, isSubscription) if (isSubscription) t else (if (ev.optional) t else t.nonNull).list } - override def resolve(value: ZStream[R1, Nothing, A]): Step[R1] = StreamStep(value.map(ev.resolve)(Trace.empty)) + override def resolve(value: ZStream[R1, Nothing, A]): Step[R1] = StreamStep(value.map(ev.resolve)) } implicit def streamSchema[R0, R1 >: R0, R2 >: R0, E <: Throwable, A](implicit ev: Schema[R2, A] @@ -564,7 +561,7 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { val t = ev.toType_(isInput, isSubscription) if (isSubscription) t else (if (ev.optional) t else t.nonNull).list } - override def resolve(value: ZStream[R1, E, A]): Step[R0] = StreamStep(value.map(ev.resolve)(Trace.empty)) + override def resolve(value: ZStream[R1, E, A]): Step[R0] = StreamStep(value.map(ev.resolve)) } def customErrorStreamSchema[R0, R1 >: R0, R2 >: R0, E, A](convertError: E => ExecutionError)(implicit ev: Schema[R2, A] @@ -575,9 +572,7 @@ trait GenericSchema[R] extends SchemaDerivation[R] with TemporalSchema { val t = ev.toType_(isInput, isSubscription) if (isSubscription) t else (if (ev.optional) t else t.nonNull).list } - override def resolve(value: ZStream[R1, E, A]): Step[R0] = StreamStep( - value.mapBoth(convertError, ev.resolve)(implicitly, Trace.empty) - ) + override def resolve(value: ZStream[R1, E, A]): Step[R0] = StreamStep(value.mapBoth(convertError, ev.resolve)) } } From 88cc87280b8f54d54d6c346b6c9a56590c69bb13 Mon Sep 17 00:00:00 2001 From: Kyri Petrou Date: Fri, 22 Dec 2023 17:35:38 +1100 Subject: [PATCH 3/4] Use `updateAndGet` on AtomicReference --- .../main/scala/caliban/InternalUtils.scala | 25 ------------------- .../caliban/wrappers/ApolloTracing.scala | 11 ++++---- .../scala/caliban/wrappers/FieldMetrics.scala | 9 +++---- .../tracing/ApolloFederatedTracing.scala | 9 +++---- 4 files changed, 13 insertions(+), 41 deletions(-) delete mode 100644 core/src/main/scala/caliban/InternalUtils.scala diff --git a/core/src/main/scala/caliban/InternalUtils.scala b/core/src/main/scala/caliban/InternalUtils.scala deleted file mode 100644 index cf35256015..0000000000 --- a/core/src/main/scala/caliban/InternalUtils.scala +++ /dev/null @@ -1,25 +0,0 @@ -package caliban - -import zio.{ UIO, ZIO } - -import java.util.concurrent.atomic.AtomicReference - -private[caliban] object InternalUtils { - - def newAtomicRef[A](a: A): UIO[AtomicReference[A]] = ZIO.succeed(new AtomicReference(a)) - - object syntax { - implicit class AtomicRefOps[A](private val ref: AtomicReference[A]) extends AnyVal { - def update(f: A => A): Unit = { - var loop = true - var next: A = null.asInstanceOf[A] - while (loop) { - val current = ref.get - next = f(current) - loop = !ref.compareAndSet(current, next) - } - () - } - } - } -} diff --git a/core/src/main/scala/caliban/wrappers/ApolloTracing.scala b/core/src/main/scala/caliban/wrappers/ApolloTracing.scala index 254defacd7..58a1928e2f 100644 --- a/core/src/main/scala/caliban/wrappers/ApolloTracing.scala +++ b/core/src/main/scala/caliban/wrappers/ApolloTracing.scala @@ -1,6 +1,5 @@ package caliban.wrappers -import caliban.InternalUtils.syntax._ import caliban.ResponseValue.{ ListValue, ObjectValue } import caliban.Value.{ IntValue, StringValue } import caliban._ @@ -35,7 +34,7 @@ object ApolloTracing { ZIO .whenZIO(isEnabledRef.get)( for { - ref <- InternalUtils.newAtomicRef(Tracing()) + ref <- ZIO.succeed(new AtomicReference(Tracing())) clock <- ZIO.clock } yield apolloTracingOverall(clock, ref) |+| apolloTracingParsing(clock, ref) |+| @@ -136,7 +135,7 @@ object ApolloTracing { for { nanoTime <- clock.nanoTime currentTime <- clock.currentTime(TimeUnit.MILLISECONDS) - _ <- ZIO.succeed(ref.update(_.copy(startTime = currentTime, startTimeMonotonic = nanoTime))) + _ <- ZIO.succeed(ref.updateAndGet(_.copy(startTime = currentTime, startTimeMonotonic = nanoTime))) result <- process(request).timed.flatMap { case (duration, result) => for { endTime <- clock.currentTime(TimeUnit.MILLISECONDS) @@ -164,7 +163,7 @@ object ApolloTracing { resultWithDuration <- process(query).timed (duration, result) = resultWithDuration _ <- ZIO.succeed( - ref.update(state => + ref.updateAndGet(state => state.copy( parsing = state.parsing .copy(startOffset = start - state.startTimeMonotonic, durationNanos = duration.toNanos) @@ -186,7 +185,7 @@ object ApolloTracing { (duration, result) = resultWithDuration _ <- ZIO.succeed( - ref.update(state => + ref.updateAndGet(state => state.copy( validation = state.validation .copy(startOffset = start - state.startTimeMonotonic, durationNanos = duration.toNanos) @@ -210,7 +209,7 @@ object ApolloTracing { val start = nanoTime query.map { result => val end = nanoTime - ref.update(state => + val _ = ref.updateAndGet(state => state.copy( execution = state.execution.copy( resolvers = Resolver( diff --git a/core/src/main/scala/caliban/wrappers/FieldMetrics.scala b/core/src/main/scala/caliban/wrappers/FieldMetrics.scala index 17e9f98bc1..c5879a8a14 100644 --- a/core/src/main/scala/caliban/wrappers/FieldMetrics.scala +++ b/core/src/main/scala/caliban/wrappers/FieldMetrics.scala @@ -1,6 +1,5 @@ package caliban.wrappers -import caliban.InternalUtils.syntax._ import caliban.Value.StringValue import caliban._ import caliban.execution.FieldInfo @@ -60,8 +59,8 @@ object FieldMetrics { ): Wrapper.EffectfulWrapper[Any] = Wrapper.EffectfulWrapper( for { - timings <- InternalUtils.newAtomicRef(List.empty[Timing]) - failures <- InternalUtils.newAtomicRef(List.empty[String]) + timings <- ZIO.succeed(new AtomicReference(List.empty[Timing])) + failures <- ZIO.succeed(new AtomicReference(List.empty[String])) clock <- ZIO.clock metrics = new Metrics(totalLabel, durationLabel, buckets, extraLabels) } yield overallWrapper(timings, failures, metrics) |+| @@ -147,13 +146,13 @@ object FieldMetrics { query.foldQuery( e => ZQuery.fail { - failures.update(fieldName :: _) + val _ = failures.updateAndGet(fieldName :: _) e }, result => ZQuery.succeed { val t = makeTiming(nanoTime - st) - timings.update(t :: _) + val _ = timings.updateAndGet(t :: _) result } ) diff --git a/federation/src/main/scala/caliban/federation/tracing/ApolloFederatedTracing.scala b/federation/src/main/scala/caliban/federation/tracing/ApolloFederatedTracing.scala index 37eb0ec98b..e3ee959ec4 100644 --- a/federation/src/main/scala/caliban/federation/tracing/ApolloFederatedTracing.scala +++ b/federation/src/main/scala/caliban/federation/tracing/ApolloFederatedTracing.scala @@ -1,7 +1,6 @@ package caliban.federation.tracing import caliban.CalibanError.ExecutionError -import caliban.InternalUtils.syntax._ import caliban.ResponseValue.ObjectValue import caliban.Value.{ IntValue, StringValue } import caliban._ @@ -31,8 +30,8 @@ object ApolloFederatedTracing { def wrapper(excludePureFields: Boolean = false): EffectfulWrapper[Any] = EffectfulWrapper( for { - tracing <- InternalUtils.newAtomicRef(Tracing(NodeTrie.empty)) - enabled <- InternalUtils.newAtomicRef(false) + tracing <- ZIO.succeed(new AtomicReference(Tracing(NodeTrie.empty))) + enabled <- ZIO.succeed(new AtomicReference(false)) clock <- ZIO.clock } yield apolloTracingOverall(clock, tracing, enabled) |+| Unsafe.unsafe(implicit u => apolloTracingField(clock.unsafe.nanoTime(), tracing, enabled, !excludePureFields)) @@ -65,7 +64,7 @@ object ApolloFederatedTracing { )( for { startNano <- clock.nanoTime - _ <- ZIO.succeed(ref.update(_.copy(startTime = startNano))) + _ <- ZIO.succeed(ref.updateAndGet(_.copy(startTime = startNano))) response <- process(request).summarized(clock.currentTime(TimeUnit.MILLISECONDS))((_, _)) ((start, end), result) = response endNano <- clock.nanoTime @@ -110,7 +109,7 @@ object ApolloFederatedTracing { ZQuery.fromEither { val endTime = nanoTime val path = (PathValue.Key(fieldInfo.name) :: fieldInfo.path).toVector - ref.update(state => + val _ = ref.updateAndGet(state => state.copy( root = state.root.insert( path, From 8590f41626b4730a914105c8089f1bf32b9dba3b Mon Sep 17 00:00:00 2001 From: Kyri Petrou Date: Fri, 22 Dec 2023 17:50:32 +1100 Subject: [PATCH 4/4] Pre-determine string builder's size --- core/src/main/scala/caliban/wrappers/FieldMetrics.scala | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/core/src/main/scala/caliban/wrappers/FieldMetrics.scala b/core/src/main/scala/caliban/wrappers/FieldMetrics.scala index c5879a8a14..2ad7e0a6ec 100644 --- a/core/src/main/scala/caliban/wrappers/FieldMetrics.scala +++ b/core/src/main/scala/caliban/wrappers/FieldMetrics.scala @@ -130,7 +130,8 @@ object FieldMetrics { def fieldName: String = { val parent = info.parent.flatMap(_.name).getOrElse("Unknown") - new StringBuilder().append(parent).append('.').append(info.name).result() + val name = info.name + new StringBuilder(name.length + parent.length + 1).append(parent).append('.').append(name).result() } def makeTiming(duration: Long) =