Upgrade to version 1.1.2 breaks IntrospectionQuery

[tkmax83]

We have noticed that the Documentation section in the graphiql UI is no longer returning the schema documentation. After debugging and going back through commits it appears that the upgrade from Spring boot 3.0.2 -> 3.0.3 where the spring-graphql was updated from 1.1.1 -> 1.1.2 breaks the IntrospectionQuery call and causes it to not return and show an "Error fetching schema". This section is incredibly important for our documentation purposes.

[bclozel]

Could you share a sample application reproducing the issue?

Is there a chance this is related to spring-projects/spring-framework#30031 and your project path contains spaces or special characters?

[tkmax83]

Here is an example repo that I was able to reproduce in. What I noticed in setting up this repo is that MVC is working properly it seems that just WebFlux is having the issue. The example repo is currently on Spring-Boot v3.0.2 and works but in the pom if you change it to 3.0.3 it starts to fail when navigating to localhost:8080/graphiql

https://github.com/tkmax83/GraphQL

[bclozel]

Thanks for the sample @tkmax83 - indeed changing the Spring Boot version to 3.0.3 fails when the GraphiQL UI sends an introspection query. Interestingly, other queries seem to work fine.

Here are the logs when this happens:

2023-03-01T18:08:08.734+01:00 DEBUG 5722 --- [nio-8080-exec-4] o.s.w.s.adapter.HttpWebHandlerAdapter    : [680d4e86] HTTP POST "/graphql"
2023-03-01T18:08:08.734+01:00 DEBUG 5722 --- [nio-8080-exec-4] o.s.w.r.f.s.s.RouterFunctionMapping      : [680d4e86] Mapped to org.springframework.boot.autoconfigure.graphql.reactive.GraphQlWebFluxAutoConfiguration$$Lambda$1005/0x0000000801090528@9de3c97
2023-03-01T18:08:08.735+01:00 DEBUG 5722 --- [nio-8080-exec-4] org.springframework.web.HttpLogging      : [680d4e86] Decoded [{query=<EOL>    query IntrospectionQuery {<EOL>      __schema {<EOL>        <EOL>        queryType { name }<EOL>         (truncated)...]
2023-03-01T18:08:08.736+01:00 DEBUG 5722 --- [nio-8080-exec-4] o.s.g.server.webflux.GraphQlHttpHandler  : Executing: document='
    query IntrospectionQuery {
      __schema {
        
        queryType { name }
        mutationType { name }
        subscriptionType { name }
        types {
          ...FullType
        }
        directives {
          name
          description
          
          locations
          args {
            ...InputValue
          }
        }
      }
    }

    fragment FullType on __Type {
      kind
      name
      description
      
      fields(includeDeprecated: true) {
        name
        description
        args {
          ...InputValue
        }
        type {
          ...TypeRef
        }
        isDeprecated
        deprecationReason
      }
      inputFields {
        ...InputValue
      }
      interfaces {
        ...TypeRef
      }
      enumValues(includeDeprecated: true) {
        name
        description
        isDeprecated
        deprecationReason
      }
      possibleTypes {
        ...TypeRef
      }
    }

    fragment InputValue on __InputValue {
      name
      description
      type { ...TypeRef }
      defaultValue
      
      
    }

    fragment TypeRef on __Type {
      kind
      name
      ofType {
        kind
        name
        ofType {
          kind
          name
          ofType {
            kind
            name
            ofType {
              kind
              name
              ofType {
                kind
                name
                ofType {
                  kind
                  name
                  ofType {
                    kind
                    name
                  }
                }
              }
            }
          }
        }
      }
    }
  ', operationName='IntrospectionQuery', id=680d4e86, Locale=en_US
2023-03-01T18:08:08.762+01:00 DEBUG 5722 --- [nio-8080-exec-4] o.s.g.server.webflux.GraphQlHttpHandler  : Execution complete
2023-03-01T18:08:08.764+01:00 DEBUG 5722 --- [nio-8080-exec-4] org.springframework.web.HttpLogging      : [680d4e86] Encoding [{data={__schema={queryType={name=Query}, mutationType=null, subscriptionType=null, types=[{kind=SCAL (truncated)...]
2023-03-01T18:08:08.768+01:00 ERROR 5722 --- [nio-8080-exec-4] o.s.w.s.adapter.HttpWebHandlerAdapter    : [680d4e86] Error [java.nio.ReadOnlyBufferException] for HTTP POST "/graphql", but ServerHttpResponse already committed (200 OK)
2023-03-01T18:08:08.768+01:00 DEBUG 5722 --- [nio-8080-exec-4] org.springframework.web.HttpLogging      : [680d4e86] AsyncEvent onError: java.nio.ReadOnlyBufferException

Here's the stack:

"http-nio-8080-exec-2@6814" daemon prio=5 tid=0x22 nid=NA runnable
  java.lang.Thread.State: RUNNABLE
	  at org.springframework.web.server.adapter.HttpWebHandlerAdapter.handleUnresolvedError(HttpWebHandlerAdapter.java:311)
	  at org.springframework.web.server.adapter.HttpWebHandlerAdapter.lambda$handle$3(HttpWebHandlerAdapter.java:252)
	  at org.springframework.web.server.adapter.HttpWebHandlerAdapter$$Lambda$1105/0x0000000801103208.apply(Unknown Source:-1)
	  at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:94)
	  at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.onError(MonoPeekTerminal.java:258)
	  at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:106)
	  at reactor.core.publisher.Operators.error(Operators.java:198)
	  at reactor.core.publisher.MonoError.subscribe(MonoError.java:53)
	  at reactor.core.publisher.Mono.subscribe(Mono.java:4485)
	  at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:103)
	  at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:106)
	  at reactor.core.publisher.Operators.error(Operators.java:198)
	  at reactor.core.publisher.MonoError.subscribe(MonoError.java:53)
	  at reactor.core.publisher.Mono.subscribe(Mono.java:4485)
	  at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:103)
	  at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:106)
	  at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onError(FluxOnAssembly.java:544)
	  at reactor.core.publisher.Operators.error(Operators.java:198)
	  at reactor.core.publisher.MonoError.subscribe(MonoError.java:53)
	  at reactor.core.publisher.Mono.subscribe(Mono.java:4485)
	  at reactor.core.publisher.FluxOnErrorResume$ResumeSubscriber.onError(FluxOnErrorResume.java:103)
	  at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondError(MonoFlatMap.java:241)
	  at reactor.core.publisher.MonoFlatMap$FlatMapInner.onError(MonoFlatMap.java:315)
	  at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondError(MonoFlatMap.java:241)
	  at reactor.core.publisher.MonoFlatMap$FlatMapInner.onError(MonoFlatMap.java:315)
	  at reactor.core.publisher.FluxOnAssembly$OnAssemblySubscriber.onError(FluxOnAssembly.java:544)
	  at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onError(FluxContextWrite.java:121)
	  at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondError(MonoFlatMap.java:241)
	  at reactor.core.publisher.MonoFlatMap$FlatMapInner.onError(MonoFlatMap.java:315)
	  at reactor.core.publisher.FluxContextWrite$ContextWriteSubscriber.onError(FluxContextWrite.java:121)
	  at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.onError(MonoPeekTerminal.java:258)
	  at reactor.core.publisher.MonoFlatMap$FlatMapMain.secondError(MonoFlatMap.java:241)
	  at reactor.core.publisher.MonoFlatMap$FlatMapInner.onError(MonoFlatMap.java:315)
	  at reactor.core.publisher.FluxPeekFuseable$PeekFuseableSubscriber.onError(FluxPeekFuseable.java:234)
	  at reactor.core.publisher.MonoPeekTerminal$MonoTerminalPeekSubscriber.onError(MonoPeekTerminal.java:258)
	  at reactor.core.publisher.MonoIgnoreElements$IgnoreElementsSubscriber.onError(MonoIgnoreElements.java:84)
	  at reactor.core.publisher.FluxConcatArray$ConcatArraySubscriber.onError(FluxConcatArray.java:207)
	  at reactor.core.publisher.MonoNext$NextSubscriber.onError(MonoNext.java:93)
	  at reactor.core.publisher.MonoNext$NextSubscriber.onError(MonoNext.java:93)
	  at org.springframework.http.server.reactive.WriteResultPublisher$State.publishError(WriteResultPublisher.java:277)
	  at org.springframework.http.server.reactive.WriteResultPublisher.publishError(WriteResultPublisher.java:99)
	  at org.springframework.http.server.reactive.AbstractListenerWriteFlushProcessor$State.onError(AbstractListenerWriteFlushProcessor.java:405)
	  at org.springframework.http.server.reactive.AbstractListenerWriteFlushProcessor.onError(AbstractListenerWriteFlushProcessor.java:133)
	  at org.springframework.http.server.reactive.AbstractListenerWriteFlushProcessor$State$WriteResultSubscriber.onError(AbstractListenerWriteFlushProcessor.java:455)
	  at org.springframework.http.server.reactive.WriteResultPublisher$State.publishError(WriteResultPublisher.java:277)
	  at org.springframework.http.server.reactive.WriteResultPublisher.publishError(WriteResultPublisher.java:99)
	  at org.springframework.http.server.reactive.AbstractListenerWriteProcessor$State.onError(AbstractListenerWriteProcessor.java:479)
	  at org.springframework.http.server.reactive.AbstractListenerWriteProcessor.onError(AbstractListenerWriteProcessor.java:132)
	  at org.springframework.http.server.reactive.ServletServerHttpResponse$ResponseAsyncListener.handleError(ServletServerHttpResponse.java:274)
	  at org.springframework.http.server.reactive.ServletServerHttpResponse$ResponseBodyWriteListener.onError(ServletServerHttpResponse.java:318)
	  at org.apache.catalina.connector.CoyoteAdapter.asyncDispatch(CoyoteAdapter.java:195)
	  at org.apache.coyote.AbstractProcessor.dispatch(AbstractProcessor.java:243)
	  at org.apache.coyote.AbstractProcessorLight.process(AbstractProcessorLight.java:52)
	  at org.apache.coyote.AbstractProtocol$ConnectionHandler.process(AbstractProtocol.java:859)
	  at org.apache.tomcat.util.net.NioEndpoint$SocketProcessor.doRun(NioEndpoint.java:1734)
	  at org.apache.tomcat.util.net.SocketProcessorBase.run(SocketProcessorBase.java:52)
	  at org.apache.tomcat.util.threads.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1191)
	  at org.apache.tomcat.util.threads.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:659)
	  at org.apache.tomcat.util.threads.TaskThread$WrappingRunnable.run(TaskThread.java:61)
	  at java.lang.Thread.run(Thread.java:833)

Interestingly, this only happens when Tomcat is involved - removing spring-boot-starter-tomcat from the sample works.
Also, downgrading the Spring Framework version to 6.0.4 (but keeping Tomcat around) also works:

<properties>
	<java.version>17</java.version>
	<spring-framework.version>6.0.4</spring-framework.version>
</properties>

Could this be a regression introduced in Spring Framework 6.0.5, or a change that uncovers a problem in Spring for GraphQL. I'm seeing two issues related to buffer management, spring-projects/spring-framework/issues#29943 and spring-projects/spring-framework#29889.

[bclozel]

I've found that the actual java.nio.ReadOnlyBufferException is raised by org.apache.coyote.http11.filters.GzipOutputFilter#doWrite when compressing the JSON response, trying to write to a java.nio.HeapByteBuffer. So disable server compression with server.compression.enabled=false also makes the issue go away.

I'm working on a reduced reproducer for this.

[poutsma]

This is most likely due to a bug in Tomcat's GzipOutputFilter that was not triggered before Spring Framework 6.0.5. See https://bz.apache.org/bugzilla/show_bug.cgi?id=66511

[bclozel]

Thanks @poutsma for the analysis. I'm closing this issue as a result.