diff --git a/.formatter.exs b/.formatter.exs index b44b2b9..cd16567 100644 --- a/.formatter.exs +++ b/.formatter.exs @@ -2,5 +2,5 @@ [ inputs: ["{mix,.formatter}.exs", "{config,lib,test}/**/*.{ex,exs}"], line_length: 120, - import_deps: [:absinthe] + import_deps: [:absinthe, :protobuf] ] diff --git a/CONTRIBUTING.md b/CONTRIBUTING.md index 8485ab7..7d93ed3 100644 --- a/CONTRIBUTING.md +++ b/CONTRIBUTING.md @@ -9,6 +9,19 @@ To get started with the project, run `mix deps.get` in the root directory to ins ```sh $ mix deps.get ``` + +To run tests: + +```sh +$ mix test +``` + +To generate tracing proto: + +```sh +$ protoc --elixir_out=./lib/absinthe/federation reports.proto +``` + ### Commit message convention We follow the [conventional commits specification](https://www.conventionalcommits.org/en) for our commit messages: diff --git a/README.md b/README.md index 4323c36..94df772 100644 --- a/README.md +++ b/README.md @@ -121,6 +121,49 @@ defmodule MySchema do end ``` +## Tracing + +### Register Middlware + +```elixir +defmodule MyApp.MySchema do + use Absinthe.Schema + use Absinthe.Federation.Schema ++ use Absinthe.Federation.Tracing + + query do + ... + end +end +``` + +If you have a custom middleware stack, add the federation tracing middleware to the **beginning** of your middleware stack: + +```elixir +def middleware(middleware, _field, _object), + do: [Absinthe.Federation.Tracing.Middleware] ++ [...your other middlewares] +``` + +### Register the Pipeline + +Specify the pipeline in your Absinthe.Plug endpoint: + +```elixir +forward "/graphql", Absinthe.Plug, + schema: MyApp.MySchema, + pipeline: {Absinthe.Federation.Tracing.Pipeline, :plug} +``` + +If you have your own pipeline function, you can add the phases directly: + +```elixir +def my_pipeline_creator(config, pipeline_opts) do + config.schema_mod + |> Absinthe.Pipeline.for_document(pipeline_opts) + |> add_my_phases() # w.e your custom phases are + |> Absinthe.Federation.Tracing.Pipeline.add_phases(pipeline_opts) # Add at the end +end +``` ## More Documentation See additional documentation, including guides, in the [Absinthe.Federation hexdocs](https://hexdocs.pm/absinthe_federation). diff --git a/lib/absinthe/federation/plug.ex b/lib/absinthe/federation/plug.ex new file mode 100644 index 0000000..eb88d64 --- /dev/null +++ b/lib/absinthe/federation/plug.ex @@ -0,0 +1,24 @@ +defmodule Absinthe.Federation.Plug do + @behaviour Plug + import Plug.Conn + + @impl Plug + defdelegate init(opts), to: Absinthe.Plug + + @impl Plug + @spec call(Plug.Conn.t(), map) :: Plug.Conn.t() | no_return + def call(conn, config) do + config = + conn + |> get_req_header("apollo-federation-include-trace") + |> case do + [include_trace] -> + put_in(config, [:context, :apollo_federation_include_trace], include_trace) + + _ -> + config + end + + Absinthe.Plug.call(conn, config) + end +end diff --git a/lib/absinthe/federation/reports.pb.ex b/lib/absinthe/federation/reports.pb.ex new file mode 100644 index 0000000..f9359c2 --- /dev/null +++ b/lib/absinthe/federation/reports.pb.ex @@ -0,0 +1,749 @@ +defmodule Absinthe.Federation.Trace.CachePolicy.Scope do + @moduledoc false + use Protobuf, enum: true, syntax: :proto3 + + @type t :: integer | :UNKNOWN | :PUBLIC | :PRIVATE + + field :UNKNOWN, 0 + field :PUBLIC, 1 + field :PRIVATE, 2 +end + +defmodule Absinthe.Federation.Trace.HTTP.Method do + @moduledoc false + use Protobuf, enum: true, syntax: :proto3 + + @type t :: + integer + | :UNKNOWN + | :OPTIONS + | :GET + | :HEAD + | :POST + | :PUT + | :DELETE + | :TRACE + | :CONNECT + | :PATCH + + field :UNKNOWN, 0 + field :OPTIONS, 1 + field :GET, 2 + field :HEAD, 3 + field :POST, 4 + field :PUT, 5 + field :DELETE, 6 + field :TRACE, 7 + field :CONNECT, 8 + field :PATCH, 9 +end + +defmodule Absinthe.Federation.Trace.CachePolicy do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + scope: Absinthe.Federation.Trace.CachePolicy.Scope.t(), + max_age_ns: integer + } + defstruct [:scope, :max_age_ns] + + field :scope, 1, type: Absinthe.Federation.Trace.CachePolicy.Scope, enum: true + field :max_age_ns, 2, type: :int64 +end + +defmodule Absinthe.Federation.Trace.Details.VariablesJsonEntry do + @moduledoc false + use Protobuf, map: true, syntax: :proto3 + + @type t :: %__MODULE__{ + key: String.t(), + value: String.t() + } + defstruct [:key, :value] + + field :key, 1, type: :string + field :value, 2, type: :string +end + +defmodule Absinthe.Federation.Trace.Details do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + variables_json: %{String.t() => String.t()}, + operation_name: String.t() + } + defstruct [:variables_json, :operation_name] + + field :variables_json, 4, + repeated: true, + type: Absinthe.Federation.Trace.Details.VariablesJsonEntry, + map: true + + field :operation_name, 3, type: :string +end + +defmodule Absinthe.Federation.Trace.Error do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + message: String.t(), + location: [Absinthe.Federation.Trace.Location.t()], + time_ns: non_neg_integer, + json: String.t() + } + defstruct [:message, :location, :time_ns, :json] + + field :message, 1, type: :string + field :location, 2, repeated: true, type: Absinthe.Federation.Trace.Location + field :time_ns, 3, type: :uint64 + field :json, 4, type: :string +end + +defmodule Absinthe.Federation.Trace.HTTP.Values do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + value: [String.t()] + } + defstruct [:value] + + field :value, 1, repeated: true, type: :string +end + +defmodule Absinthe.Federation.Trace.HTTP.RequestHeadersEntry do + @moduledoc false + use Protobuf, map: true, syntax: :proto3 + + @type t :: %__MODULE__{ + key: String.t(), + value: Absinthe.Federation.Trace.HTTP.Values.t() | nil + } + defstruct [:key, :value] + + field :key, 1, type: :string + field :value, 2, type: Absinthe.Federation.Trace.HTTP.Values +end + +defmodule Absinthe.Federation.Trace.HTTP.ResponseHeadersEntry do + @moduledoc false + use Protobuf, map: true, syntax: :proto3 + + @type t :: %__MODULE__{ + key: String.t(), + value: Absinthe.Federation.Trace.HTTP.Values.t() | nil + } + defstruct [:key, :value] + + field :key, 1, type: :string + field :value, 2, type: Absinthe.Federation.Trace.HTTP.Values +end + +defmodule Absinthe.Federation.Trace.HTTP do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + method: Absinthe.Federation.Trace.HTTP.Method.t(), + host: String.t(), + path: String.t(), + request_headers: %{String.t() => Absinthe.Federation.Trace.HTTP.Values.t() | nil}, + response_headers: %{String.t() => Absinthe.Federation.Trace.HTTP.Values.t() | nil}, + status_code: non_neg_integer, + secure: boolean, + protocol: String.t() + } + defstruct [ + :method, + :host, + :path, + :request_headers, + :response_headers, + :status_code, + :secure, + :protocol + ] + + field :method, 1, type: Absinthe.Federation.Trace.HTTP.Method, enum: true + field :host, 2, type: :string + field :path, 3, type: :string + + field :request_headers, 4, + repeated: true, + type: Absinthe.Federation.Trace.HTTP.RequestHeadersEntry, + map: true + + field :response_headers, 5, + repeated: true, + type: Absinthe.Federation.Trace.HTTP.ResponseHeadersEntry, + map: true + + field :status_code, 6, type: :uint32 + field :secure, 8, type: :bool + field :protocol, 9, type: :string +end + +defmodule Absinthe.Federation.Trace.Location do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + line: non_neg_integer, + column: non_neg_integer + } + defstruct [:line, :column] + + field :line, 1, type: :uint32 + field :column, 2, type: :uint32 +end + +defmodule Absinthe.Federation.Trace.Node do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + id: {atom, any}, + original_field_name: String.t(), + type: String.t(), + parent_type: String.t(), + cache_policy: Absinthe.Federation.Trace.CachePolicy.t() | nil, + start_time: non_neg_integer, + end_time: non_neg_integer, + error: [Absinthe.Federation.Trace.Error.t()], + child: [Absinthe.Federation.Trace.Node.t()] + } + defstruct [ + :id, + :original_field_name, + :type, + :parent_type, + :cache_policy, + :start_time, + :end_time, + :error, + :child + ] + + oneof :id, 0 + field :response_name, 1, type: :string, oneof: 0 + field :index, 2, type: :uint32, oneof: 0 + field :original_field_name, 14, type: :string + field :type, 3, type: :string + field :parent_type, 13, type: :string + field :cache_policy, 5, type: Absinthe.Federation.Trace.CachePolicy + field :start_time, 8, type: :uint64 + field :end_time, 9, type: :uint64 + field :error, 11, repeated: true, type: Absinthe.Federation.Trace.Error + field :child, 12, repeated: true, type: Absinthe.Federation.Trace.Node +end + +defmodule Absinthe.Federation.Trace.QueryPlanNode.SequenceNode do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + nodes: [Absinthe.Federation.Trace.QueryPlanNode.t()] + } + defstruct [:nodes] + + field :nodes, 1, repeated: true, type: Absinthe.Federation.Trace.QueryPlanNode +end + +defmodule Absinthe.Federation.Trace.QueryPlanNode.ParallelNode do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + nodes: [Absinthe.Federation.Trace.QueryPlanNode.t()] + } + defstruct [:nodes] + + field :nodes, 1, repeated: true, type: Absinthe.Federation.Trace.QueryPlanNode +end + +defmodule Absinthe.Federation.Trace.QueryPlanNode.FetchNode do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + service_name: String.t(), + trace_parsing_failed: boolean, + trace: Absinthe.Federation.Trace.t() | nil, + sent_time_offset: non_neg_integer, + sent_time: Google.Protobuf.Timestamp.t() | nil, + received_time: Google.Protobuf.Timestamp.t() | nil + } + defstruct [ + :service_name, + :trace_parsing_failed, + :trace, + :sent_time_offset, + :sent_time, + :received_time + ] + + field :service_name, 1, type: :string + field :trace_parsing_failed, 2, type: :bool + field :trace, 3, type: Absinthe.Federation.Trace + field :sent_time_offset, 4, type: :uint64 + field :sent_time, 5, type: Google.Protobuf.Timestamp + field :received_time, 6, type: Google.Protobuf.Timestamp +end + +defmodule Absinthe.Federation.Trace.QueryPlanNode.FlattenNode do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + response_path: [Absinthe.Federation.Trace.QueryPlanNode.ResponsePathElement.t()], + node: Absinthe.Federation.Trace.QueryPlanNode.t() | nil + } + defstruct [:response_path, :node] + + field :response_path, 1, + repeated: true, + type: Absinthe.Federation.Trace.QueryPlanNode.ResponsePathElement + + field :node, 2, type: Absinthe.Federation.Trace.QueryPlanNode +end + +defmodule Absinthe.Federation.Trace.QueryPlanNode.ResponsePathElement do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + id: {atom, any} + } + defstruct [:id] + + oneof :id, 0 + field :field_name, 1, type: :string, oneof: 0 + field :index, 2, type: :uint32, oneof: 0 +end + +defmodule Absinthe.Federation.Trace.QueryPlanNode do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + node: {atom, any} + } + defstruct [:node] + + oneof :node, 0 + field :sequence, 1, type: Absinthe.Federation.Trace.QueryPlanNode.SequenceNode, oneof: 0 + field :parallel, 2, type: Absinthe.Federation.Trace.QueryPlanNode.ParallelNode, oneof: 0 + field :fetch, 3, type: Absinthe.Federation.Trace.QueryPlanNode.FetchNode, oneof: 0 + field :flatten, 4, type: Absinthe.Federation.Trace.QueryPlanNode.FlattenNode, oneof: 0 +end + +defmodule Absinthe.Federation.Trace do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + start_time: Google.Protobuf.Timestamp.t() | nil, + end_time: Google.Protobuf.Timestamp.t() | nil, + duration_ns: non_neg_integer, + root: Absinthe.Federation.Trace.Node.t() | nil, + signature: String.t(), + unexecutedOperationBody: String.t(), + unexecutedOperationName: String.t(), + details: Absinthe.Federation.Trace.Details.t() | nil, + client_name: String.t(), + client_version: String.t(), + client_address: String.t(), + client_reference_id: String.t(), + http: Absinthe.Federation.Trace.HTTP.t() | nil, + cache_policy: Absinthe.Federation.Trace.CachePolicy.t() | nil, + query_plan: Absinthe.Federation.Trace.QueryPlanNode.t() | nil, + full_query_cache_hit: boolean, + persisted_query_hit: boolean, + persisted_query_register: boolean, + registered_operation: boolean, + forbidden_operation: boolean + } + defstruct [ + :start_time, + :end_time, + :duration_ns, + :root, + :signature, + :unexecutedOperationBody, + :unexecutedOperationName, + :details, + :client_name, + :client_version, + :client_address, + :client_reference_id, + :http, + :cache_policy, + :query_plan, + :full_query_cache_hit, + :persisted_query_hit, + :persisted_query_register, + :registered_operation, + :forbidden_operation + ] + + field :start_time, 4, type: Google.Protobuf.Timestamp + field :end_time, 3, type: Google.Protobuf.Timestamp + field :duration_ns, 11, type: :uint64 + field :root, 14, type: Absinthe.Federation.Trace.Node + field :signature, 19, type: :string + field :unexecutedOperationBody, 27, type: :string + field :unexecutedOperationName, 28, type: :string + field :details, 6, type: Absinthe.Federation.Trace.Details + field :client_name, 7, type: :string + field :client_version, 8, type: :string + field :client_address, 9, type: :string + field :client_reference_id, 23, type: :string + field :http, 10, type: Absinthe.Federation.Trace.HTTP + field :cache_policy, 18, type: Absinthe.Federation.Trace.CachePolicy + field :query_plan, 26, type: Absinthe.Federation.Trace.QueryPlanNode + field :full_query_cache_hit, 20, type: :bool + field :persisted_query_hit, 21, type: :bool + field :persisted_query_register, 22, type: :bool + field :registered_operation, 24, type: :bool + field :forbidden_operation, 25, type: :bool +end + +defmodule Absinthe.Federation.ReportHeader do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + graph_ref: String.t(), + hostname: String.t(), + agent_version: String.t(), + service_version: String.t(), + runtime_version: String.t(), + uname: String.t(), + executable_schema_id: String.t() + } + defstruct [ + :graph_ref, + :hostname, + :agent_version, + :service_version, + :runtime_version, + :uname, + :executable_schema_id + ] + + field :graph_ref, 12, type: :string + field :hostname, 5, type: :string + field :agent_version, 6, type: :string + field :service_version, 7, type: :string + field :runtime_version, 8, type: :string + field :uname, 9, type: :string + field :executable_schema_id, 11, type: :string +end + +defmodule Absinthe.Federation.PathErrorStats.ChildrenEntry do + @moduledoc false + use Protobuf, map: true, syntax: :proto3 + + @type t :: %__MODULE__{ + key: String.t(), + value: Absinthe.Federation.PathErrorStats.t() | nil + } + defstruct [:key, :value] + + field :key, 1, type: :string + field :value, 2, type: Absinthe.Federation.PathErrorStats +end + +defmodule Absinthe.Federation.PathErrorStats do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + children: %{String.t() => Absinthe.Federation.PathErrorStats.t() | nil}, + errors_count: non_neg_integer, + requests_with_errors_count: non_neg_integer + } + defstruct [:children, :errors_count, :requests_with_errors_count] + + field :children, 1, + repeated: true, + type: Absinthe.Federation.PathErrorStats.ChildrenEntry, + map: true + + field :errors_count, 4, type: :uint64 + field :requests_with_errors_count, 5, type: :uint64 +end + +defmodule Absinthe.Federation.QueryLatencyStats do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + latency_count: [integer], + request_count: non_neg_integer, + cache_hits: non_neg_integer, + persisted_query_hits: non_neg_integer, + persisted_query_misses: non_neg_integer, + cache_latency_count: [integer], + root_error_stats: Absinthe.Federation.PathErrorStats.t() | nil, + requests_with_errors_count: non_neg_integer, + public_cache_ttl_count: [integer], + private_cache_ttl_count: [integer], + registered_operation_count: non_neg_integer, + forbidden_operation_count: non_neg_integer + } + defstruct [ + :latency_count, + :request_count, + :cache_hits, + :persisted_query_hits, + :persisted_query_misses, + :cache_latency_count, + :root_error_stats, + :requests_with_errors_count, + :public_cache_ttl_count, + :private_cache_ttl_count, + :registered_operation_count, + :forbidden_operation_count + ] + + field :latency_count, 13, repeated: true, type: :sint64 + field :request_count, 2, type: :uint64 + field :cache_hits, 3, type: :uint64 + field :persisted_query_hits, 4, type: :uint64 + field :persisted_query_misses, 5, type: :uint64 + field :cache_latency_count, 14, repeated: true, type: :sint64 + field :root_error_stats, 7, type: Absinthe.Federation.PathErrorStats + field :requests_with_errors_count, 8, type: :uint64 + field :public_cache_ttl_count, 15, repeated: true, type: :sint64 + field :private_cache_ttl_count, 16, repeated: true, type: :sint64 + field :registered_operation_count, 11, type: :uint64 + field :forbidden_operation_count, 12, type: :uint64 +end + +defmodule Absinthe.Federation.StatsContext do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + client_reference_id: String.t(), + client_name: String.t(), + client_version: String.t() + } + defstruct [:client_reference_id, :client_name, :client_version] + + field :client_reference_id, 1, type: :string + field :client_name, 2, type: :string + field :client_version, 3, type: :string +end + +defmodule Absinthe.Federation.ContextualizedQueryLatencyStats do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + query_latency_stats: Absinthe.Federation.QueryLatencyStats.t() | nil, + context: Absinthe.Federation.StatsContext.t() | nil + } + defstruct [:query_latency_stats, :context] + + field :query_latency_stats, 1, type: Absinthe.Federation.QueryLatencyStats + field :context, 2, type: Absinthe.Federation.StatsContext +end + +defmodule Absinthe.Federation.ContextualizedTypeStats.PerTypeStatEntry do + @moduledoc false + use Protobuf, map: true, syntax: :proto3 + + @type t :: %__MODULE__{ + key: String.t(), + value: Absinthe.Federation.TypeStat.t() | nil + } + defstruct [:key, :value] + + field :key, 1, type: :string + field :value, 2, type: Absinthe.Federation.TypeStat +end + +defmodule Absinthe.Federation.ContextualizedTypeStats do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + context: Absinthe.Federation.StatsContext.t() | nil, + per_type_stat: %{String.t() => Absinthe.Federation.TypeStat.t() | nil} + } + defstruct [:context, :per_type_stat] + + field :context, 1, type: Absinthe.Federation.StatsContext + + field :per_type_stat, 2, + repeated: true, + type: Absinthe.Federation.ContextualizedTypeStats.PerTypeStatEntry, + map: true +end + +defmodule Absinthe.Federation.FieldStat do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + return_type: String.t(), + errors_count: non_neg_integer, + count: non_neg_integer, + requests_with_errors_count: non_neg_integer, + latency_count: [integer] + } + defstruct [:return_type, :errors_count, :count, :requests_with_errors_count, :latency_count] + + field :return_type, 3, type: :string + field :errors_count, 4, type: :uint64 + field :count, 5, type: :uint64 + field :requests_with_errors_count, 6, type: :uint64 + field :latency_count, 9, repeated: true, type: :sint64 +end + +defmodule Absinthe.Federation.TypeStat.PerFieldStatEntry do + @moduledoc false + use Protobuf, map: true, syntax: :proto3 + + @type t :: %__MODULE__{ + key: String.t(), + value: Absinthe.Federation.FieldStat.t() | nil + } + defstruct [:key, :value] + + field :key, 1, type: :string + field :value, 2, type: Absinthe.Federation.FieldStat +end + +defmodule Absinthe.Federation.TypeStat do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + per_field_stat: %{String.t() => Absinthe.Federation.FieldStat.t() | nil} + } + defstruct [:per_field_stat] + + field :per_field_stat, 3, + repeated: true, + type: Absinthe.Federation.TypeStat.PerFieldStatEntry, + map: true +end + +defmodule Absinthe.Federation.Field do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + name: String.t(), + return_type: String.t() + } + defstruct [:name, :return_type] + + field :name, 2, type: :string + field :return_type, 3, type: :string +end + +defmodule Absinthe.Federation.Type do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + name: String.t(), + field: [Absinthe.Federation.Field.t()] + } + defstruct [:name, :field] + + field :name, 1, type: :string + field :field, 2, repeated: true, type: Absinthe.Federation.Field +end + +defmodule Absinthe.Federation.Report.TracesPerQueryEntry do + @moduledoc false + use Protobuf, map: true, syntax: :proto3 + + @type t :: %__MODULE__{ + key: String.t(), + value: Absinthe.Federation.TracesAndStats.t() | nil + } + defstruct [:key, :value] + + field :key, 1, type: :string + field :value, 2, type: Absinthe.Federation.TracesAndStats +end + +defmodule Absinthe.Federation.Report do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + header: Absinthe.Federation.ReportHeader.t() | nil, + traces_per_query: %{String.t() => Absinthe.Federation.TracesAndStats.t() | nil}, + end_time: Google.Protobuf.Timestamp.t() | nil + } + defstruct [:header, :traces_per_query, :end_time] + + field :header, 1, type: Absinthe.Federation.ReportHeader + + field :traces_per_query, 5, + repeated: true, + type: Absinthe.Federation.Report.TracesPerQueryEntry, + map: true + + field :end_time, 2, type: Google.Protobuf.Timestamp +end + +defmodule Absinthe.Federation.ContextualizedStats.PerTypeStatEntry do + @moduledoc false + use Protobuf, map: true, syntax: :proto3 + + @type t :: %__MODULE__{ + key: String.t(), + value: Absinthe.Federation.TypeStat.t() | nil + } + defstruct [:key, :value] + + field :key, 1, type: :string + field :value, 2, type: Absinthe.Federation.TypeStat +end + +defmodule Absinthe.Federation.ContextualizedStats do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + context: Absinthe.Federation.StatsContext.t() | nil, + query_latency_stats: Absinthe.Federation.QueryLatencyStats.t() | nil, + per_type_stat: %{String.t() => Absinthe.Federation.TypeStat.t() | nil} + } + defstruct [:context, :query_latency_stats, :per_type_stat] + + field :context, 1, type: Absinthe.Federation.StatsContext + field :query_latency_stats, 2, type: Absinthe.Federation.QueryLatencyStats + + field :per_type_stat, 3, + repeated: true, + type: Absinthe.Federation.ContextualizedStats.PerTypeStatEntry, + map: true +end + +defmodule Absinthe.Federation.TracesAndStats do + @moduledoc false + use Protobuf, syntax: :proto3 + + @type t :: %__MODULE__{ + trace: [Absinthe.Federation.Trace.t()], + stats_with_context: [Absinthe.Federation.ContextualizedStats.t()], + internal_traces_contributing_to_stats: [Absinthe.Federation.Trace.t()] + } + defstruct [:trace, :stats_with_context, :internal_traces_contributing_to_stats] + + field :trace, 1, repeated: true, type: Absinthe.Federation.Trace + field :stats_with_context, 2, repeated: true, type: Absinthe.Federation.ContextualizedStats + field :internal_traces_contributing_to_stats, 3, repeated: true, type: Absinthe.Federation.Trace +end diff --git a/lib/absinthe/federation/tracing.ex b/lib/absinthe/federation/tracing.ex new file mode 100644 index 0000000..839d7e0 --- /dev/null +++ b/lib/absinthe/federation/tracing.ex @@ -0,0 +1,19 @@ +defmodule Absinthe.Federation.Tracing do + @moduledoc """ + Documentation for Absinthe.Federation.Tracing. + """ + + def version, do: 1 + + defmacro __using__(_) do + quote do + def middleware(middleware, _, %{identifier: :subscription}), do: middleware + + def middleware(middleware, _, %{identifier: :mutation}), + do: [Absinthe.Federation.Tracing.Middleware] ++ middleware + + def middleware(middleware, _, _), + do: [Absinthe.Federation.Tracing.Middleware] ++ middleware + end + end +end diff --git a/lib/absinthe/federation/tracing/middleware.ex b/lib/absinthe/federation/tracing/middleware.ex new file mode 100644 index 0000000..539f1d8 --- /dev/null +++ b/lib/absinthe/federation/tracing/middleware.ex @@ -0,0 +1,77 @@ +defmodule Absinthe.Federation.Tracing.Middleware do + @behaviour Absinthe.Middleware + + alias Absinthe.Resolution + + # Called before resolving + # if there isn't an `federation_tracing` flag set then we aren't actually doing any tracing + def call( + %Resolution{ + extensions: extensions, + acc: %{federation_tracing_start_time: start_mono_time}, + state: :unresolved + } = res, + opts + ) do + now = System.monotonic_time(:nanosecond) + path_details = List.first(res.path) + + id = + case path_details do + idx when is_integer(idx) -> + {:index, idx} + + %{alias: nil, name: response_name} -> + {:response_name, response_name} + + %{alias: response_name} -> + {:response_name, response_name} + end + + original_field_name = + case path_details do + %{alias: alias_name, name: name} when not is_nil(alias_name) -> + name + + _ -> + "" + end + + node = + Absinthe.Federation.Trace.Node.new(%{ + id: id, + original_field_name: original_field_name, + type: Absinthe.Type.name(res.definition.schema_node.type, res.schema), + parent_type: res.parent_type.name, + # relative to the trace's start_time, in ns + start_time: now - start_mono_time, + child: [] + }) + + %{ + res + | extensions: Map.put(extensions, __MODULE__, node), + middleware: res.middleware ++ [{{__MODULE__, :after_field}, opts}] + } + end + + def call(res, _opts), do: res + + # Called after each resolution to calculate the end_time + def after_field( + %Resolution{ + state: :resolved, + extensions: %{__MODULE__ => node} = extensions, + acc: %{federation_tracing_start_time: start_mono_time} + } = res, + _opts + ) do + now = System.monotonic_time(:nanosecond) + # relative to the trace's start_time, in ns + updated_node = %{node | end_time: now - start_mono_time} + + %{res | extensions: Map.put(extensions, __MODULE__, updated_node)} + end + + def after_field(res, _), do: res +end diff --git a/lib/absinthe/federation/tracing/phase/accumulate_result.ex b/lib/absinthe/federation/tracing/phase/accumulate_result.ex new file mode 100644 index 0000000..1d37337 --- /dev/null +++ b/lib/absinthe/federation/tracing/phase/accumulate_result.ex @@ -0,0 +1,97 @@ +defmodule Absinthe.Federation.Tracing.Pipeline.Phase.AccumulateResult do + @moduledoc false + + alias Absinthe.Blueprint + alias Absinthe.Blueprint.Result + + use Absinthe.Phase + + @impl Absinthe.Phase + @spec run(Blueprint.t() | Phase.Error.t(), Keyword.t()) :: {:ok, map} + def run(blueprint, options \\ []) + + def run( + %Blueprint{execution: %{acc: %{federation_trace: trace, federation_tracing_start_time: start_mono_time}}} = + blueprint, + _options + ) do + now = System.monotonic_time(:nanosecond) + + duration = now - start_mono_time + end_time = Absinthe.Federation.Tracing.Timestamp.now!() + trace = %{trace | duration_ns: duration, end_time: end_time} + blueprint = put_in(blueprint.execution.acc.federation_trace, trace) + + {:ok, accumulate_trace(blueprint)} + end + + def run(blueprint, _options), do: {:ok, blueprint} + + defp accumulate_trace( + %Blueprint{execution: %{result: %Result.Object{} = result, acc: %{federation_trace: _trace}}} = blueprint + ) do + root_trace_node = accumulate_trace(result) + put_in(blueprint.execution.acc.federation_trace.root, root_trace_node) + end + + defp accumulate_trace(%Blueprint{} = blueprint), do: blueprint + + # Leaf + defp accumulate_trace(%Result.Leaf{ + value: _, + errors: errors, + extensions: %{Absinthe.Federation.Tracing.Middleware => trace_node} + }) do + node_errors = + Enum.map(errors, fn %{message: message, locations: locations} = _error -> + node_error_locations = + Enum.map(locations, fn %{line: line, column: column} -> + Absinthe.Federation.Trace.Location.new(%{line: line, column: column}) + end) + + Absinthe.Federation.Trace.Error.new(%{ + message: message, + location: node_error_locations, + # TODO: Encode error in JSON string + json: %{} + }) + end) + + %{trace_node | error: node_errors} + end + + # Object + defp accumulate_trace(%Result.Object{ + fields: fields, + extensions: %{Absinthe.Federation.Tracing.Middleware => trace_node} + }) + when is_list(fields) do + children = Enum.map(fields, &accumulate_trace/1) + %{trace_node | child: children} + end + + # List + defp accumulate_trace(%Result.List{ + values: values, + extensions: %{Absinthe.Federation.Tracing.Middleware => trace_node} + }) + when is_list(values) do + children = + values + |> Enum.with_index() + |> Enum.map(fn {value, idx} -> + Absinthe.Federation.Trace.Node.new(%{ + id: {:index, idx}, + child: List.wrap(accumulate_trace(value)) + }) + end) + + %{trace_node | child: children} + end + + # Root query + defp accumulate_trace(%Result.Object{fields: fields}) do + children = Enum.map(fields, &accumulate_trace/1) + Absinthe.Federation.Trace.Node.new(%{child: children}) + end +end diff --git a/lib/absinthe/federation/tracing/phase/add_extension.ex b/lib/absinthe/federation/tracing/phase/add_extension.ex new file mode 100644 index 0000000..2074c6d --- /dev/null +++ b/lib/absinthe/federation/tracing/phase/add_extension.ex @@ -0,0 +1,26 @@ +defmodule Absinthe.Federation.Tracing.Pipeline.Phase.AddExtension do + use Absinthe.Phase + + require Logger + + @impl Absinthe.Phase + def run(blueprint, options \\ []) + + def run(%Absinthe.Blueprint{result: result, execution: %{acc: %{federation_trace: trace}}} = blueprint, _options) do + encoded_trace = + trace + |> Absinthe.Federation.Trace.encode() + |> Base.encode64() + + extensions = + result + |> Map.get(:extensions, %{}) + |> Map.put(:ftv1, encoded_trace) + + result = Map.put(result, :extensions, extensions) + + {:ok, %{blueprint | result: result}} + end + + def run(blueprint, _options), do: {:ok, blueprint} +end diff --git a/lib/absinthe/federation/tracing/phase/create_trace.ex b/lib/absinthe/federation/tracing/phase/create_trace.ex new file mode 100644 index 0000000..717ea17 --- /dev/null +++ b/lib/absinthe/federation/tracing/phase/create_trace.ex @@ -0,0 +1,31 @@ +defmodule Absinthe.Federation.Tracing.Pipeline.Phase.CreateTrace do + use Absinthe.Phase + + @impl Absinthe.Phase + def run(blueprint, options \\ []) + + def run(blueprint, options) when is_list(options), + do: options |> Enum.into(%{}) |> run_phase(blueprint) + + def run(blueprint, _options), do: {:ok, blueprint} + + defp run_phase( + %{context: %{apollo_federation_include_trace: "ftv1"}} = _options, + %Absinthe.Blueprint{execution: %{acc: acc}} = blueprint + ) do + trace = + Absinthe.Federation.Trace.new(%{ + # Wallclock time when the trace started. + start_time: Absinthe.Federation.Tracing.Timestamp.now!() + }) + + new_acc = + acc + |> Map.put(:federation_trace, trace) + |> Map.put(:federation_tracing_start_time, System.monotonic_time(:nanosecond)) + + {:ok, put_in(blueprint.execution.acc, new_acc)} + end + + defp run_phase(_options, blueprint), do: {:ok, blueprint} +end diff --git a/lib/absinthe/federation/tracing/pipeline.ex b/lib/absinthe/federation/tracing/pipeline.ex new file mode 100644 index 0000000..2300600 --- /dev/null +++ b/lib/absinthe/federation/tracing/pipeline.ex @@ -0,0 +1,33 @@ +defmodule Absinthe.Federation.Tracing.Pipeline do + alias Absinthe.Federation.Tracing + + def default(schema, pipeline_opts \\ []) do + schema + |> Absinthe.Pipeline.for_document(pipeline_opts) + |> add_phases(pipeline_opts) + end + + if Code.ensure_loaded?(Absinthe.Plug) do + def plug(config, pipeline_opts \\ []) do + config + |> Absinthe.Plug.default_pipeline(pipeline_opts) + |> add_phases(pipeline_opts) + end + end + + def add_phases(pipeline, pipeline_opts) do + pipeline + |> Absinthe.Pipeline.insert_after( + Absinthe.Phase.Blueprint, + {Tracing.Pipeline.Phase.CreateTrace, pipeline_opts} + ) + |> Absinthe.Pipeline.insert_before( + Absinthe.Phase.Document.Result, + Tracing.Pipeline.Phase.AccumulateResult + ) + |> Absinthe.Pipeline.insert_after( + Absinthe.Phase.Document.Result, + Tracing.Pipeline.Phase.AddExtension + ) + end +end diff --git a/lib/absinthe/federation/tracing/timestamp.ex b/lib/absinthe/federation/tracing/timestamp.ex new file mode 100644 index 0000000..12c23be --- /dev/null +++ b/lib/absinthe/federation/tracing/timestamp.ex @@ -0,0 +1,47 @@ +defmodule Absinthe.Federation.Tracing.Timestamp do + @moduledoc """ + Helper functions for converting from elixir datetimes to protobuf timestamps and back. + """ + alias Google.Protobuf.Timestamp + + @type unix_timestamp :: integer + + @nano_multiplier 1_000_000_000 + @utc "Etc/UTC" + + @doc """ + Convert a NaiveDateTime or a DateTime (while truncating timezone) to a Google.Protobuf.Timestamp + """ + @spec serialize(NaiveDateTime.t() | DateTime.t() | nil) :: Timestamp.t() | nil + def serialize(nil), do: nil + + def serialize(%NaiveDateTime{} = naive_datetime) do + naive_datetime + |> DateTime.from_naive!(@utc) + |> serialize() + end + + def serialize(%DateTime{} = datetime) do + nanoseconds_since_epoch = DateTime.to_unix(datetime, :nanosecond) + seconds = div(nanoseconds_since_epoch, @nano_multiplier) + nanos = rem(nanoseconds_since_epoch, @nano_multiplier) + + Timestamp.new(seconds: seconds, nanos: nanos) + end + + @doc """ + Convert a Google.Protobuf.Timestamp to a DateTime + """ + @spec deserialize(Timestamp.t() | nil) :: DateTime.t() | nil + def deserialize(nil), do: nil + + def deserialize(timestamp) do + nanoseconds_since_epoch = timestamp.seconds * @nano_multiplier + timestamp.nanos + + nanoseconds_since_epoch + |> DateTime.from_unix!(:nanosecond) + end + + @spec now!() :: Timestamp.t() + def now!(), do: @utc |> DateTime.now!() |> serialize() +end diff --git a/mix.exs b/mix.exs index 567af9a..67211e3 100644 --- a/mix.exs +++ b/mix.exs @@ -64,9 +64,14 @@ defmodule Absinthe.Federation.MixProject do defp deps do [ {:absinthe, "~> 1.6.5"}, + {:absinthe_plug, "~> 1.5.8"}, {:dataloader, "~> 1.0.9"}, + {:plug, "~> 1.4"}, + {:protobuf, "~> 0.7.1"}, + {:google_protos, "~> 0.1"}, # Dev + {:jason, ">= 0.0.0", only: [:dev, :test]}, {:dialyxir, "~> 1.0.0", only: [:dev, :test], runtime: false}, {:ex_doc, "~> 0.24", only: :dev, runtime: false} ] diff --git a/mix.lock b/mix.lock index bcb66ce..23d1b7d 100644 --- a/mix.lock +++ b/mix.lock @@ -1,13 +1,20 @@ %{ "absinthe": {:hex, :absinthe, "1.6.6", "d4b3d87c868264edf47fbf9c152155f31e8d26c370607f5fe92f6e106d190b74", [:mix], [{:dataloader, "~> 1.0.0", [hex: :dataloader, repo: "hexpm", optional: true]}, {:decimal, "~> 1.0 or ~> 2.0", [hex: :decimal, repo: "hexpm", optional: true]}, {:nimble_parsec, "~> 0.5 or ~> 1.0", [hex: :nimble_parsec, repo: "hexpm", optional: false]}, {:telemetry, "~> 1.0 or ~> 0.4", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "a03e18478b19bdf81ed1eef9b0853edf4496a080c2048ed17993dc945a90bedc"}, + "absinthe_plug": {:hex, :absinthe_plug, "1.5.8", "38d230641ba9dca8f72f1fed2dfc8abd53b3907d1996363da32434ab6ee5d6ab", [:mix], [{:absinthe, "~> 1.5", [hex: :absinthe, repo: "hexpm", optional: false]}, {:plug, "~> 1.4", [hex: :plug, repo: "hexpm", optional: false]}], "hexpm", "bbb04176647b735828861e7b2705465e53e2cf54ccf5a73ddd1ebd855f996e5a"}, "dataloader": {:hex, :dataloader, "1.0.9", "8fb981e327fa692f741ab283ed93790203a6f6d412800f0f4f1531372e1dbf15", [:mix], [{:ecto, ">= 3.4.3 and < 4.0.0", [hex: :ecto, repo: "hexpm", optional: true]}, {:telemetry, "~> 0.4", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "6f8b7566c8dda46f53bdb336fd02f03f00bf58aeb6cc0f139ccdfd6f99d265a7"}, "dialyxir": {:hex, :dialyxir, "1.0.0", "6a1fa629f7881a9f5aaf3a78f094b2a51a0357c843871b8bc98824e7342d00a5", [:mix], [{:erlex, ">= 0.2.6", [hex: :erlex, repo: "hexpm", optional: false]}], "hexpm", "aeb06588145fac14ca08d8061a142d52753dbc2cf7f0d00fc1013f53f8654654"}, "earmark_parser": {:hex, :earmark_parser, "1.4.16", "607709303e1d4e3e02f1444df0c821529af1c03b8578dfc81bb9cf64553d02b9", [:mix], [], "hexpm", "69fcf696168f5a274dd012e3e305027010658b2d1630cef68421d6baaeaccead"}, "erlex": {:hex, :erlex, "0.2.6", "c7987d15e899c7a2f34f5420d2a2ea0d659682c06ac607572df55a43753aa12e", [:mix], [], "hexpm", "2ed2e25711feb44d52b17d2780eabf998452f6efda104877a3881c2f8c0c0c75"}, "ex_doc": {:hex, :ex_doc, "0.25.3", "3edf6a0d70a39d2eafde030b8895501b1c93692effcbd21347296c18e47618ce", [:mix], [{:earmark_parser, "~> 1.4.0", [hex: :earmark_parser, repo: "hexpm", optional: false]}, {:makeup_elixir, "~> 0.14", [hex: :makeup_elixir, repo: "hexpm", optional: false]}, {:makeup_erlang, "~> 0.1", [hex: :makeup_erlang, repo: "hexpm", optional: false]}], "hexpm", "9ebebc2169ec732a38e9e779fd0418c9189b3ca93f4a676c961be6c1527913f5"}, + "google_protos": {:hex, :google_protos, "0.1.0", "c6b9e12092d17571b093d4156d004494ca143b65dbbcbfc3ffff463ea03467c0", [:mix], [{:protobuf, "~> 0.5", [hex: :protobuf, repo: "hexpm", optional: false]}], "hexpm", "ff5564525f89d2638a4cfa9fb4d31e9ee9d9d7cb937b3e8a95f558440c039e1b"}, + "jason": {:hex, :jason, "1.3.0", "fa6b82a934feb176263ad2df0dbd91bf633d4a46ebfdffea0c8ae82953714946", [:mix], [{:decimal, "~> 1.0 or ~> 2.0", [hex: :decimal, repo: "hexpm", optional: true]}], "hexpm", "53fc1f51255390e0ec7e50f9cb41e751c260d065dcba2bf0d08dc51a4002c2ac"}, "makeup": {:hex, :makeup, "1.0.5", "d5a830bc42c9800ce07dd97fa94669dfb93d3bf5fcf6ea7a0c67b2e0e4a7f26c", [:mix], [{:nimble_parsec, "~> 0.5 or ~> 1.0", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "cfa158c02d3f5c0c665d0af11512fed3fba0144cf1aadee0f2ce17747fba2ca9"}, "makeup_elixir": {:hex, :makeup_elixir, "0.15.1", "b5888c880d17d1cc3e598f05cdb5b5a91b7b17ac4eaf5f297cb697663a1094dd", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}, {:nimble_parsec, "~> 1.1", [hex: :nimble_parsec, repo: "hexpm", optional: false]}], "hexpm", "db68c173234b07ab2a07f645a5acdc117b9f99d69ebf521821d89690ae6c6ec8"}, "makeup_erlang": {:hex, :makeup_erlang, "0.1.1", "3fcb7f09eb9d98dc4d208f49cc955a34218fc41ff6b84df7c75b3e6e533cc65f", [:mix], [{:makeup, "~> 1.0", [hex: :makeup, repo: "hexpm", optional: false]}], "hexpm", "174d0809e98a4ef0b3309256cbf97101c6ec01c4ab0b23e926a9e17df2077cbb"}, + "mime": {:hex, :mime, "2.0.2", "0b9e1a4c840eafb68d820b0e2158ef5c49385d17fb36855ac6e7e087d4b1dcc5", [:mix], [], "hexpm", "e6a3f76b4c277739e36c2e21a2c640778ba4c3846189d5ab19f97f126df5f9b7"}, "nimble_parsec": {:hex, :nimble_parsec, "1.1.0", "3a6fca1550363552e54c216debb6a9e95bd8d32348938e13de5eda962c0d7f89", [:mix], [], "hexpm", "08eb32d66b706e913ff748f11694b17981c0b04a33ef470e33e11b3d3ac8f54b"}, + "plug": {:hex, :plug, "1.12.1", "645678c800601d8d9f27ad1aebba1fdb9ce5b2623ddb961a074da0b96c35187d", [:mix], [{:mime, "~> 1.0 or ~> 2.0", [hex: :mime, repo: "hexpm", optional: false]}, {:plug_crypto, "~> 1.1.1 or ~> 1.2", [hex: :plug_crypto, repo: "hexpm", optional: false]}, {:telemetry, "~> 0.4.3 or ~> 1.0", [hex: :telemetry, repo: "hexpm", optional: false]}], "hexpm", "d57e799a777bc20494b784966dc5fbda91eb4a09f571f76545b72a634ce0d30b"}, + "plug_crypto": {:hex, :plug_crypto, "1.2.2", "05654514ac717ff3a1843204b424477d9e60c143406aa94daf2274fdd280794d", [:mix], [], "hexpm", "87631c7ad914a5a445f0a3809f99b079113ae4ed4b867348dd9eec288cecb6db"}, + "protobuf": {:hex, :protobuf, "0.7.1", "7d1b9f7d9ecb32eccd96b0c58572de4d1c09e9e3bc414e4cb15c2dce7013f195", [:mix], [], "hexpm", "6eff7a5287963719521c82e5d5b4583fd1d7cdd89ad129f0ea7d503a50a4d13f"}, "telemetry": {:hex, :telemetry, "0.4.3", "a06428a514bdbc63293cd9a6263aad00ddeb66f608163bdec7c8995784080818", [:rebar3], [], "hexpm", "eb72b8365ffda5bed68a620d1da88525e326cb82a75ee61354fc24b844768041"}, } diff --git a/reports.proto b/reports.proto new file mode 100644 index 0000000..47858ee --- /dev/null +++ b/reports.proto @@ -0,0 +1,386 @@ +syntax = "proto3"; + +package absinthe.federation; + +import "google/protobuf/timestamp.proto"; + +message Trace { + message CachePolicy { + enum Scope { + UNKNOWN = 0; + PUBLIC = 1; + PRIVATE = 2; + } + + Scope scope = 1; + int64 max_age_ns = 2; // use 0 for absent, -1 for 0 + } + + message Details { + // The variables associated with this query (unless the reporting agent is + // configured to keep them all private). Values are JSON: ie, strings are + // enclosed in double quotes, etc. The value of a private variable is + // the empty string. + map variables_json = 4; + + + // This is deprecated and only used for legacy applications + // don't include this in traces inside a FullTracesReport; the operation + // name for these traces comes from the key of the traces_per_query map. + string operation_name = 3; + } + + message Error { + string message = 1; // required + repeated Location location = 2; + uint64 time_ns = 3; + string json = 4; + } + + message HTTP { + message Values { + repeated string value = 1; + } + + enum Method { + UNKNOWN = 0; + OPTIONS = 1; + GET = 2; + HEAD = 3; + POST = 4; + PUT = 5; + DELETE = 6; + TRACE = 7; + CONNECT = 8; + PATCH = 9; + } + Method method = 1; + string host = 2; + string path = 3; + + // Should exclude manual blacklist ("Auth" by default) + map request_headers = 4; + map response_headers = 5; + + uint32 status_code = 6; + + bool secure = 8; // TLS was used + string protocol = 9; // by convention "HTTP/1.0", "HTTP/1.1", "HTTP/2" or "h2" + } + + message Location { + uint32 line = 1; + uint32 column = 2; + } + + // We store information on each resolver execution as a Node on a tree. + // The structure of the tree corresponds to the structure of the GraphQL + // response; it does not indicate the order in which resolvers were + // invoked. Note that nodes representing indexes (and the root node) + // don't contain all Node fields (eg types and times). + message Node { + // The name of the field (for Nodes representing a resolver call) or the + // index in a list (for intermediate Nodes representing elements of a list). + // field_name is the name of the field as it appears in the GraphQL + // response: ie, it may be an alias. (In that case, the original_field_name + // field holds the actual field name from the schema.) In any context where + // we're building up a path, we use the response_name rather than the + // original_field_name. + oneof id { + string response_name = 1; + uint32 index = 2; + } + + string original_field_name = 14; + + // The field's return type; e.g. "String!" for User.email:String! + string type = 3; + + // The field's parent type; e.g. "User" for User.email:String! + string parent_type = 13; + + CachePolicy cache_policy = 5; + + // relative to the trace's start_time, in ns + uint64 start_time = 8; + // relative to the trace's start_time, in ns + uint64 end_time = 9; + + repeated Error error = 11; + repeated Node child = 12; + + reserved 4; + } + + // represents a node in the query plan, under which there is a trace tree for that service fetch. + // In particular, each fetch node represents a call to an implementing service, and calls to implementing + // services may not be unique. See https://github.com/apollographql/apollo-server/blob/main/packages/apollo-gateway/src/QueryPlan.ts + // for more information and details. + message QueryPlanNode { + // This represents a set of nodes to be executed sequentially by the Gateway executor + message SequenceNode { + repeated QueryPlanNode nodes = 1; + } + // This represents a set of nodes to be executed in parallel by the Gateway executor + message ParallelNode { + repeated QueryPlanNode nodes = 1; + } + // This represents a node to send an operation to an implementing service + message FetchNode { + // XXX When we want to include more details about the sub-operation that was + // executed against this service, we should include that here in each fetch node. + // This might include an operation signature, requires directive, reference resolutions, etc. + string service_name = 1; + + bool trace_parsing_failed = 2; + + // This Trace only contains start_time, end_time, duration_ns, and root; + // all timings were calculated **on the federated service**, and clock skew + // will be handled by the ingress server. + Trace trace = 3; + + // relative to the outer trace's start_time, in ns, measured in the gateway. + uint64 sent_time_offset = 4; + + // Wallclock times measured in the gateway for when this operation was + // sent and received. + google.protobuf.Timestamp sent_time = 5; + google.protobuf.Timestamp received_time = 6; + } + + // This node represents a way to reach into the response path and attach related entities. + // XXX Flatten is really not the right name and this node may be renamed in the query planner. + message FlattenNode { + repeated ResponsePathElement response_path = 1; + QueryPlanNode node = 2; + } + message ResponsePathElement { + oneof id { + string field_name = 1; + uint32 index = 2; + } + } + oneof node { + SequenceNode sequence = 1; + ParallelNode parallel = 2; + FetchNode fetch = 3; + FlattenNode flatten = 4; + } + } + + // Wallclock time when the trace began. + google.protobuf.Timestamp start_time = 4; // required + // Wallclock time when the trace ended. + google.protobuf.Timestamp end_time = 3; // required + // High precision duration of the trace; may not equal end_time-start_time + // (eg, if your machine's clock changed during the trace). + uint64 duration_ns = 11; // required + // A tree containing information about all resolvers run directly by this + // service, including errors. + Node root = 14; + + // ------------------------------------------------------------------------- + // Fields below this line are *not* included in federated traces (the traces + // sent from federated services to the gateway). + + // In addition to details.raw_query, we include a "signature" of the query, + // which can be normalized: for example, you may want to discard aliases, drop + // unused operations and fragments, sort fields, etc. The most important thing + // here is that the signature match the signature in StatsReports. In + // StatsReports signatures show up as the key in the per_query map (with the + // operation name prepended). The signature should be a valid GraphQL query. + // All traces must have a signature; if this Trace is in a FullTracesReport + // that signature is in the key of traces_per_query rather than in this field. + // Engineproxy provides the signature in legacy_signature_needs_resigning + // instead. + string signature = 19; + + // Optional: when GraphQL parsing or validation against the GraphQL schema fails, these fields + // can include reference to the operation being sent for users to dig into the set of operations + // that are failing validation. + string unexecutedOperationBody = 27; + string unexecutedOperationName = 28; + + Details details = 6; + + // Note: engineproxy always sets client_name, client_version, and client_address to "none". + // apollo-engine-reporting allows for them to be set by the user. + string client_name = 7; + string client_version = 8; + string client_address = 9; + string client_reference_id = 23; + + HTTP http = 10; + + CachePolicy cache_policy = 18; + + // If this Trace was created by a gateway, this is the query plan, including + // sub-Traces for federated services. Note that the 'root' tree on the + // top-level Trace won't contain any resolvers (though it could contain errors + // that occurred in the gateway itself). + QueryPlanNode query_plan = 26; + + // Was this response served from a full query response cache? (In that case + // the node tree will have no resolvers.) + bool full_query_cache_hit = 20; + + // Was this query specified successfully as a persisted query hash? + bool persisted_query_hit = 21; + // Did this query contain both a full query string and a persisted query hash? + // (This typically means that a previous request was rejected as an unknown + // persisted query.) + bool persisted_query_register = 22; + + // Was this operation registered and a part of the safelist? + bool registered_operation = 24; + + // Was this operation forbidden due to lack of safelisting? + bool forbidden_operation = 25; + + + + // removed: Node parse = 12; Node validate = 13; + // Id128 server_id = 1; Id128 client_id = 2; + reserved 12, 13, 1, 2; +} + +// The `service` value embedded within the header key is not guaranteed to contain an actual service, +// and, in most cases, the service information is trusted to come from upstream processing. If the +// service _is_ specified in this header, then it is checked to match the context that is reporting it. +// Otherwise, the service information is deduced from the token context of the reporter and then sent +// along via other mechanisms (in Kafka, the `ReportKafkaKey). The other information (hostname, +// agent_version, etc.) is sent by the Apollo Engine Reporting agent, but we do not currently save that +// information to any of our persistent storage. +message ReportHeader { + // eg "mygraph@myvariant" + string graph_ref = 12; + + // eg "host-01.example.com" + string hostname = 5; + + // eg "engineproxy 0.1.0" + string agent_version = 6; // required + // eg "prod-4279-20160804T065423Z-5-g3cf0aa8" (taken from `git describe --tags`) + string service_version = 7; + // eg "node v4.6.0" + string runtime_version = 8; + // eg "Linux box 4.6.5-1-ec2 #1 SMP Mon Aug 1 02:31:38 PDT 2016 x86_64 GNU/Linux" + string uname = 9; + // An id that is used to represent the schema to Apollo Graph Manager + // Using this in place of what used to be schema_hash, since that is no longer + // attached to a schema in the backend. + string executable_schema_id = 11; + + reserved 3; // removed string service = 3; +} + +message PathErrorStats { + map children = 1; + uint64 errors_count = 4; + uint64 requests_with_errors_count = 5; +} + +message QueryLatencyStats { + repeated sint64 latency_count = 13; // [(js_use_toArray)=true]; + uint64 request_count = 2; + uint64 cache_hits = 3; + uint64 persisted_query_hits = 4; + uint64 persisted_query_misses = 5; + repeated sint64 cache_latency_count = 14; // [(js_use_toArray)=true]; + PathErrorStats root_error_stats = 7; + uint64 requests_with_errors_count = 8; + repeated sint64 public_cache_ttl_count = 15; // [(js_use_toArray)=true]; + repeated sint64 private_cache_ttl_count = 16; // [(js_use_toArray)=true]; + uint64 registered_operation_count = 11; + uint64 forbidden_operation_count = 12; + // 1, 6, 9, and 10 were old int64 histograms + reserved 1, 6, 9, 10; +} + +message StatsContext { + string client_reference_id = 1; + string client_name = 2; + string client_version = 3; +} + +message ContextualizedQueryLatencyStats { + QueryLatencyStats query_latency_stats = 1; + StatsContext context = 2; +} + +message ContextualizedTypeStats { + StatsContext context = 1; + map per_type_stat = 2; +} + +message FieldStat { + string return_type = 3; // required; eg "String!" for User.email:String! + uint64 errors_count = 4; + uint64 count = 5; + uint64 requests_with_errors_count = 6; + repeated sint64 latency_count = 9; // [(js_use_toArray)=true]; // Duration histogram; see docs/histograms.md + reserved 1, 2, 7, 8; +} + +message TypeStat { + // Key is (eg) "email" for User.email:String! + map per_field_stat = 3; + reserved 1, 2; +} + + +message Field { + string name = 2; // required; eg "email" for User.email:String! + string return_type = 3; // required; eg "String!" for User.email:String! +} + +message Type { + string name = 1; // required; eg "User" for User.email:String! + repeated Field field = 2; +} + +// This is the top-level message used by the new traces ingress. This +// is designed for the apollo-engine-reporting TypeScript agent and will +// eventually be documented as a public ingress API. This message consists +// solely of traces; the equivalent of the StatsReport is automatically +// generated server-side from this message. Agent should either send a trace or include it in the stats +// for every request in this report. Generally, buffering up until a large +// size has been reached (say, 4MB) or 5-10 seconds has passed is appropriate. +// This message used to be know as FullTracesReport, but got renamed since it isn't just for traces anymore +message Report { + ReportHeader header = 1; + + // key is statsReportKey (# operationName\nsignature) Note that the nested + // traces will *not* have a signature or details.operationName (because the + // key is adequate). + // + // We also assume that traces don't have + // legacy_per_query_implicit_operation_name, and we don't require them to have + // details.raw_query (which would consume a lot of space and has privacy/data + // access issues, and isn't currently exposed by our app anyway). + map traces_per_query = 5; + + // This is the time that the requests in this trace are considered to have taken place + // If this field is not present the max of the end_time of each trace will be used instead. + // If there are no traces and no end_time present the report will not be able to be processed. + // Note: This will override the end_time from traces. + google.protobuf.Timestamp end_time = 2; // required if no traces in this message +} + +message ContextualizedStats { + StatsContext context = 1; + QueryLatencyStats query_latency_stats = 2; + // Key is type name. + map per_type_stat = 3; + +} + +// A sequence of traces and stats. An individual trace should either be counted as a stat or trace +message TracesAndStats { + repeated Trace trace = 1; // [(js_preEncoded)=true]; + repeated ContextualizedStats stats_with_context = 2; // [(js_use_toArray)=true]; + // This field is used to validate that the algorithm used to construct `stats_with_context` + // matches similar algorithms in Apollo's servers. It is otherwise ignored and should not + // be included in reports. + repeated Trace internal_traces_contributing_to_stats = 3; // [(js_preEncoded)=true]; +} diff --git a/test/absinthe/federation/plug_test.exs b/test/absinthe/federation/plug_test.exs new file mode 100644 index 0000000..ff2151e --- /dev/null +++ b/test/absinthe/federation/plug_test.exs @@ -0,0 +1,49 @@ +defmodule Absinthe.Federation.PlugTest do + use Absinthe.Federation.Case, async: true + + defmodule TestSchema do + use Absinthe.Schema + use Absinthe.Federation.Schema + use Absinthe.Federation.Tracing + + query do + extends() + + # absinthe requires query to contain at least 1 root query field + field :foo, :boolean + end + end + + @query """ + { + foo + } + """ + + test "header enables tracing" do + opts = Absinthe.Federation.Plug.init(schema: TestSchema, pipeline: {Absinthe.Federation.Tracing.Pipeline, :plug}) + + response = + conn(:post, "/", @query) + |> put_req_header("content-type", "application/graphql") + |> put_req_header("apollo-federation-include-trace", "ftv1") + |> plug_parser + |> Absinthe.Federation.Plug.call(opts) + + assert %{status: 200, resp_body: resp_body} = response + assert resp_body =~ "{\"data\":{\"foo\":null},\"extensions\":{\"ftv1\":\"" + end + + test "no header disables tracing" do + opts = Absinthe.Federation.Plug.init(schema: TestSchema, pipeline: {Absinthe.Federation.Tracing.Pipeline, :plug}) + + response = + conn(:post, "/", @query) + |> put_req_header("content-type", "application/graphql") + |> plug_parser + |> Absinthe.Federation.Plug.call(opts) + + assert %{status: 200, resp_body: resp_body} = response + assert ~s({"data":{"foo":null}}) == resp_body + end +end diff --git a/test/absinthe/federation/tracing_test.exs b/test/absinthe/federation/tracing_test.exs new file mode 100644 index 0000000..ee7ff07 --- /dev/null +++ b/test/absinthe/federation/tracing_test.exs @@ -0,0 +1,213 @@ +defmodule Absinthe.Federation.TracingTests do + use Absinthe.Federation.Case, async: true + + defmodule TestSchema do + use Absinthe.Schema + use Absinthe.Federation.Tracing + + object :person do + field(:name, :string) + field(:age, non_null(:integer)) + field(:cars, list_of(:car)) + end + + object :car do + field(:make, non_null(:string)) + field(:model, non_null(:string)) + end + + query do + field :get_person, list_of(non_null(:person)) do + resolve(fn _, _ -> + {:ok, + [ + %{ + name: "sikan", + age: nil, + cars: [%{make: "Honda", model: "Civic"}] + } + ]} + end) + end + end + end + + test "should have :ftv1 in extensions" do + query = """ + query { + getPerson { + name + cars { + make + model + } + } + } + """ + + %{extensions: extensions} = get_result(TestSchema, query) + assert Map.has_key?(extensions, :ftv1) + end + + test "alias has original_field_name set correctly" do + query = """ + query { + getPerson { + personName: name + } + } + """ + + %{root: %{child: [%{child: [%{child: [%{child: [person_name_node]}]}]}]}} = get_decoded_trace(TestSchema, query) + + assert person_name_node.id == {:response_name, "personName"} + assert person_name_node.original_field_name == "name" + end + + test "sets root trace fields" do + query = """ + query { getPerson { name } } + """ + + trace = get_decoded_trace(TestSchema, query) + + assert trace.start_time != nil + assert trace.end_time != nil + assert trace.duration_ns != nil + end + + test "sets trace node fields" do + query = """ + query { getPerson { name } } + """ + + %{root: %{child: [get_person_trace_node]}} = get_decoded_trace(TestSchema, query) + + assert get_person_trace_node.id == {:response_name, "getPerson"} + assert get_person_trace_node.start_time != nil + assert get_person_trace_node.end_time != nil + assert get_person_trace_node.parent_type == "RootQueryType" + assert get_person_trace_node.type == "[Person!]" + end + + test "sets list trace node children" do + query = """ + query { getPerson { age } } + """ + + # %{root: %{child: [%{ + # cache_policy: nil, + # child: [], + # end_time: 38_062_000, + # error: [ + # %Absinthe.Federation.Trace.Error{ + # json: "", + # location: [%Absinthe.Federation.Trace.Location{column: 21, line: 1}], + # message: "Cannot return null for non-nullable field", + # time_ns: 0 + # } + # ], + # id: {:response_name, "getPerson"}, + # original_field_name: "", + # parent_type: "RootQueryType", + # start_time: 35_654_000, + # type: "[Person!]" + # } + # ], + # end_time: 0, + # error: [], + # id: nil, + # original_field_name: "", + # parent_type: "", + # start_time: 0, + # type: "" + # }, + # } + + %{root: %{child: [%{child: [index_node]}]}} = get_decoded_trace(TestSchema, query) + + assert index_node.end_time == 0 + assert index_node.error == [] + assert index_node.id == {:index, 0} + assert index_node.original_field_name == "" + assert index_node.parent_type == "" + assert index_node.start_time == 0 + assert index_node.type == "" + end + + test "sets trace node error fields" do + query = """ + query { getPerson { age } } + """ + + # %Absinthe.Federation.Trace{ + # root: %Absinthe.Federation.Trace.Node{ + # child: [ + # %Absinthe.Federation.Trace.Node{ + # child: [], + # end_time: 272_000, + # error: [ + # %Absinthe.Federation.Trace.Error{ + # json: "", + # location: [%Absinthe.Federation.Trace.Location{column: 26, line: 1}], + # message: "Cannot return null for non-nullable field", + # time_ns: 0 + # } + # ], + # id: {:response_name, "getPerson"}, + # original_field_name: "", + # parent_type: "RootQueryType", + # start_time: 262_000, + # type: "[Person!]" + # } + # ], + # end_time: 0, + # error: [], + # id: nil, + # original_field_name: "", + # parent_type: "", + # start_time: 0, + # type: "" + # }, + # signature: "", + # start_time: %Google.Protobuf.Timestamp{nanos: 801_041_000, seconds: 1_642_024_406}, + # unexecutedOperationBody: "", + # unexecutedOperationName: "" + # } + + %{root: %{child: [%{child: [%{child: [person_node]}]}]}} = get_decoded_trace(TestSchema, query) + + assert person_node.id == {:response_name, "age"} + assert person_node.errors != [] + end + + test "does not include trace when header not present" do + query = """ + query { getPerson { name } } + """ + + result = get_result(TestSchema, query, []) + + refute Map.has_key?(result, :extensions) + end + + defp get_decoded_trace(schema, query, pipeline_opts \\ [context: %{apollo_federation_include_trace: "ftv1"}]) do + schema + |> get_result(query, pipeline_opts) + |> Map.get(:extensions, %{}) + |> Map.get(:ftv1, "") + |> Base.decode64!() + |> Absinthe.Federation.Trace.decode() + end + + defp get_result(schema, query, pipeline_opts \\ [context: %{apollo_federation_include_trace: "ftv1"}]) do + pipeline = Absinthe.Federation.Tracing.Pipeline.default(schema, pipeline_opts) + + query + |> Absinthe.Pipeline.run(pipeline) + |> case do + {:ok, %{result: result}, _} -> result + error -> error + end + end +end diff --git a/test/support/case.ex b/test/support/case.ex index 8258a1d..ba47a54 100644 --- a/test/support/case.ex +++ b/test/support/case.ex @@ -4,7 +4,19 @@ defmodule Absinthe.Federation.Case do defmacro __using__(opts) do quote do use ExUnit.Case, unquote(opts) + use Plug.Test import ExUnit.Case + import unquote(__MODULE__) end end + + def plug_parser(conn) do + opts = + Plug.Parsers.init( + parsers: [:urlencoded, :multipart, :json, Absinthe.Plug.Parser], + json_decoder: Jason + ) + + Plug.Parsers.call(conn, opts) + end end diff --git a/test/test_helper.exs b/test/test_helper.exs index 869559e..6a0af57 100644 --- a/test/test_helper.exs +++ b/test/test_helper.exs @@ -1 +1 @@ -ExUnit.start() +ExUnit.start(capture_log: true)