diff --git a/guides/queries/logging.md b/guides/queries/logging.md new file mode 100644 index 0000000000..75e5d9ec35 --- /dev/null +++ b/guides/queries/logging.md @@ -0,0 +1,22 @@ +--- +layout: guide +doc_stub: false +search: true +section: Queries +title: Logging +desc: Development output from GraphQL-Ruby +index: 12 +--- + +At runtime, GraphQL-Ruby will output debug information using {{ "GraphQL::Query.logger" | api_doc }}. By default, this uses `Rails.logger`. To see output, make sure `config.log_level = :debug` is set. (This information isn't meant for production logs.) + +You can configure a custom logger with {{ "GraphQL::Schema.default_logger" | api_doc }}, for example: + +```ruby +class MySchema < GraphQL::Schema + # This logger will be used by queries during execution: + default_logger MyCustomLogger.new +end +``` + +You can also pass `context[:logger]` to provide a logger during execution. diff --git a/lib/graphql/query.rb b/lib/graphql/query.rb index 09b21ad941..47d5931e20 100644 --- a/lib/graphql/query.rb +++ b/lib/graphql/query.rb @@ -162,6 +162,14 @@ def initialize(schema, query_string = nil, query: nil, document: nil, context: n @result_values = nil @executed = false + + @logger = if context && context[:logger] == false + Logger.new(IO::NULL) + elsif context && (l = context[:logger]) + l + else + schema.default_logger + end end # If a document was provided to `GraphQL::Schema#execute` instead of the raw query string, we will need to get it from the document @@ -369,6 +377,8 @@ def after_lazy(value, &block) end end + attr_reader :logger + private def find_operation(operations, operation_name) diff --git a/lib/graphql/query/context.rb b/lib/graphql/query/context.rb index d370a0b9d2..e9a07aa0f6 100644 --- a/lib/graphql/query/context.rb +++ b/lib/graphql/query/context.rb @@ -237,6 +237,10 @@ def namespace?(ns) @storage.key?(ns) end + def logger + @query && @query.logger + end + def inspect "#" end diff --git a/lib/graphql/schema.rb b/lib/graphql/schema.rb index 2d54108f95..393282038d 100644 --- a/lib/graphql/schema.rb +++ b/lib/graphql/schema.rb @@ -1,4 +1,5 @@ # frozen_string_literal: true +require "logger" require "graphql/schema/addition" require "graphql/schema/always_visible" require "graphql/schema/base_64_encoder" @@ -835,6 +836,26 @@ def default_analysis_engine end end + def default_logger(new_default_logger = NOT_CONFIGURED) + if NOT_CONFIGURED.equal?(new_default_logger) + if defined?(@default_logger) + @default_logger + elsif superclass.respond_to?(:default_logger) + superclass.default_logger + elsif defined?(Rails) + Rails.logger + else + def_logger = Logger.new($stdout) + def_logger.info! # It doesn't output debug info by default + def_logger + end + elsif new_default_logger == nil + @default_logger = Logger.new(IO::NULL) + else + @default_logger = new_default_logger + end + end + def context_class(new_context_class = nil) if new_context_class @context_class = new_context_class diff --git a/lib/graphql/schema/warden.rb b/lib/graphql/schema/warden.rb index 624fadf278..e03db4e83c 100644 --- a/lib/graphql/schema/warden.rb +++ b/lib/graphql/schema/warden.rb @@ -291,7 +291,14 @@ def visible_and_reachable_type?(type_defn) if type_defn.kind.union? possible_types(type_defn).any? && (referenced?(type_defn) || orphan_type?(type_defn)) elsif type_defn.kind.interface? - possible_types(type_defn).any? + if possible_types(type_defn).any? + true + else + if @context.respond_to?(:logger) && (logger = @context.logger) + logger.debug { "Interface `#{type_defn.graphql_name}` hidden because it has no visible implementors" } + end + false + end else if referenced?(type_defn) true diff --git a/spec/graphql/dataloader/async_dataloader_spec.rb b/spec/graphql/dataloader/async_dataloader_spec.rb index cd1704e603..4cbbe15738 100644 --- a/spec/graphql/dataloader/async_dataloader_spec.rb +++ b/spec/graphql/dataloader/async_dataloader_spec.rb @@ -240,13 +240,13 @@ def self.included(child_class) include AsyncDataloaderAssertions end - if RUBY_ENGINE == "ruby" && !ENV["GITHUB_ACTIONS"] - describe "With libev_scheduler" do - require "libev_scheduler" - let(:scheduler_class) { Libev::Scheduler } - include AsyncDataloaderAssertions - end - end + # if RUBY_ENGINE == "ruby" && !ENV["GITHUB_ACTIONS"] + # describe "With libev_scheduler" do + # require "libev_scheduler" + # let(:scheduler_class) { Libev::Scheduler } + # include AsyncDataloaderAssertions + # end + # end describe "with evt" do require "evt" diff --git a/spec/graphql/logger_spec.rb b/spec/graphql/logger_spec.rb new file mode 100644 index 0000000000..627769dbee --- /dev/null +++ b/spec/graphql/logger_spec.rb @@ -0,0 +1,86 @@ +# frozen_string_literal: true +require "spec_helper" + +describe "Logger" do + describe "Schema.default_logger" do + if defined?(Rails) + it "When Rails is present, returns the Rails logger" do + assert_equal Rails.logger, GraphQL::Schema.default_logger + end + else + it "Without Rails, returns a new logger" do + assert_instance_of Logger, GraphQL::Schema.default_logger + end + end + + it "can be overridden" do + new_logger = Logger.new($stdout) + schema = Class.new(GraphQL::Schema) do + default_logger(new_logger) + end + assert_equal new_logger, schema.default_logger + end + + it "can be set to a null logger with nil" do + schema = Class.new(GraphQL::Schema) + schema.default_logger(nil) + nil_logger = schema.default_logger + std_out, std_err = capture_io do + nil_logger.error("Blah") + nil_logger.warn("Something") + nil_logger.error("Hi") + end + assert_equal "", std_out + assert_equal "", std_err + end + end + + describe "during execution" do + module LoggerTest + class DefaultLoggerSchema < GraphQL::Schema + module Node + include GraphQL::Schema::Interface + field :id, ID + end + + class Query < GraphQL::Schema::Object + field :node, Node do + argument :id, ID + end + + def node(id:) + + end + end + query(Query) + end + + class CustomLoggerSchema < DefaultLoggerSchema + LOG_STRING = StringIO.new + LOGGER = Logger.new(LOG_STRING) + LOGGER.level = :debug + default_logger(LOGGER) + end + end + + before do + LoggerTest::CustomLoggerSchema::LOG_STRING.truncate(0) + end + + it "logs about hidden interfaces with no implementations" do + res = LoggerTest::CustomLoggerSchema.execute("{ node(id: \"5\") { id } }") + assert_equal ["Field 'node' doesn't exist on type 'Query'"], res["errors"].map { |err| err["message"] } + assert_includes LoggerTest::CustomLoggerSchema::LOG_STRING.string, "Interface `Node` hidden because it has no visible implementors" + end + + it "doesn't print messages by default" do + res = nil + stdout, stderr = capture_io do + res = LoggerTest::DefaultLoggerSchema.execute("{ node(id: \"5\") { id } }") + end + assert_equal ["Field 'node' doesn't exist on type 'Query'"], res["errors"].map { |err| err["message"] } + assert_equal "", stdout + assert_equal "", stderr + end + end +end