router icon indicating copy to clipboard operation
router copied to clipboard

Published 20 hours ago • verified publisher icon apollographql

Getting response malformed and Invalid type error

Open atanuk opened this issue 3 years ago • 4 comments

Describe the bug I was running Router at my local Laptop and fetching schema from Apollo Studio. But getting the below response. {"errors":[{"message":"HTTP fetch failed from 'vehicle-details': service 'vehicle-details' response was malformed: service 'vehicle-details' response was malformed: invalid type: string \"/\", expected a sequence","locations":[],"path":[],"extensions":{"type":"SubrequestHttpError","service":"vehicle-details","reason":"service 'vehicle-details' response was malformed: service 'vehicle-details' response was malformed: invalid type: string \"/\", expected a sequence"}}]} Subgraph response I am getting for the same query is

{
    "data": {
        "vehicles": [
            {
                "id": "1",
                "modelCode": "XYZ0192"
            }
        ]
    }
}

To Reproduce Steps to reproduce the behavior:

  1. Setup services 'I have set up the services in GED-Router@akarak-dev'
  2. Submit request 'Ran router using the command APOLLO_KEY=service:GED-Router:ZZ-xxx APOLLO_GRAPH_REF=GED-Router@akarak-dev ./router . Request sent query { vehicles(count: 1) { id modelCode } }'
  3. See error

Expected behavior I was expecting a valid response instead of error.

Output If applicable, add output to help explain your problem.

Desktop (please complete the following information):

  • OS: [e.g. iOS] Laptop macOS
  • Version [e.g. 22] 12.3.1

Additional context Debug Log of Router below

 $ APOLLO_KEY=service:GED-Router:xxx APOLLO_GRAPH_REF=GED-Router@akarak-dev ./router
2022-04-29T17:50:54.663736Z  INFO apollo_router::executable: [email protected]
2022-04-29T17:50:54.663903Z DEBUG apollo_router::state_machine: starting
2022-04-29T17:50:54.663969Z  INFO apollo_router: starting Apollo Router
2022-04-29T17:50:54.663988Z DEBUG apollo_router::state_machine: transitioned to state startup
2022-04-29T17:50:54.664015Z DEBUG apollo_router::state_machine: ignoring message transition NoMoreConfiguration
2022-04-29T17:50:54.664021Z DEBUG apollo_router::state_machine: transitioned to state startup
2022-04-29T17:50:54.965482Z DEBUG hyper::client::connect::dns: resolving host="uplink.api.apollographql.com"
2022-04-29T17:50:54.967018Z DEBUG hyper::client::connect::http: connecting to 34.117.186.194:443
2022-04-29T17:50:55.007919Z DEBUG hyper::client::connect::http: connected to 34.117.186.194:443
2022-04-29T17:50:55.056517Z DEBUG h2::client: binding client connection
2022-04-29T17:50:55.056544Z DEBUG h2::client: client connection bound
2022-04-29T17:50:55.056565Z DEBUG h2::codec::framed_write: send frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }
2022-04-29T17:50:55.056714Z DEBUG hyper::client::pool: pooling idle connection for ("https", uplink.api.apollographql.com)
2022-04-29T17:50:55.056886Z DEBUG Connection{peer=Client}: h2::codec::framed_write: send frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
2022-04-29T17:50:55.056944Z DEBUG Connection{peer=Client}: h2::codec::framed_write: send frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
2022-04-29T17:50:55.056971Z DEBUG Connection{peer=Client}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
2022-04-29T17:50:55.102350Z DEBUG Connection{peer=Client}: h2::codec::framed_read: received frame=Settings { flags: (0x0), max_concurrent_streams: 100, initial_window_size: 1048576, max_header_list_size: 65536 }
2022-04-29T17:50:55.102381Z DEBUG Connection{peer=Client}: h2::codec::framed_write: send frame=Settings { flags: (0x1: ACK) }
2022-04-29T17:50:55.102396Z DEBUG Connection{peer=Client}: h2::codec::framed_read: received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 983041 }
2022-04-29T17:50:55.148199Z DEBUG Connection{peer=Client}: h2::codec::framed_read: received frame=Settings { flags: (0x1: ACK) }
2022-04-29T17:50:55.148222Z DEBUG Connection{peer=Client}: h2::proto::settings: received settings ACK; applying Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }
2022-04-29T17:50:55.227249Z DEBUG Connection{peer=Client}: h2::codec::framed_read: received frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
2022-04-29T17:50:55.227300Z DEBUG Connection{peer=Client}: h2::codec::framed_read: received frame=Data { stream_id: StreamId(1) }
2022-04-29T17:50:55.229924Z DEBUG Connection{peer=Client}: h2::codec::framed_read: received frame=Data { stream_id: StreamId(1) }
2022-04-29T17:50:55.247052Z DEBUG Connection{peer=Client}: h2::codec::framed_read: received frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
2022-04-29T17:50:55.247085Z DEBUG Connection{peer=Client}: h2::codec::framed_read: received frame=Ping { ack: false, payload: [0, 0, 0, 0, 0, 0, 0, 0] }
2022-04-29T17:50:55.247094Z DEBUG Connection{peer=Client}: h2::codec::framed_write: send frame=Ping { ack: true, payload: [0, 0, 0, 0, 0, 0, 0, 0] }
2022-04-29T17:50:55.247327Z DEBUG Connection{peer=Client}: h2::codec::framed_write: send frame=GoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) }
2022-04-29T17:50:55.247348Z DEBUG Connection{peer=Client}: h2::proto::connection: Connection::poll; connection error error=GoAway(b"", NO_ERROR, Library)
2022-04-29T17:50:55.531470Z DEBUG hyper::client::connect::dns: resolving host="uplink.api.apollographql.com"
2022-04-29T17:50:55.532620Z DEBUG hyper::client::connect::http: connecting to 34.117.186.194:443
2022-04-29T17:50:55.597141Z DEBUG hyper::client::connect::http: connected to 34.117.186.194:443
2022-04-29T17:50:55.605666Z DEBUG apollo_router::state_machine: starting http
2022-04-29T17:50:55.647387Z DEBUG h2::client: binding client connection
2022-04-29T17:50:55.647409Z DEBUG h2::client: client connection bound
2022-04-29T17:50:55.647416Z DEBUG h2::codec::framed_write: send frame=Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }
2022-04-29T17:50:55.647467Z DEBUG hyper::client::pool: pooling idle connection for ("https", uplink.api.apollographql.com)
2022-04-29T17:50:55.647518Z DEBUG Connection{peer=Client}: h2::codec::framed_write: send frame=WindowUpdate { stream_id: StreamId(0), size_increment: 5177345 }
2022-04-29T17:50:55.647542Z DEBUG Connection{peer=Client}: h2::codec::framed_write: send frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
2022-04-29T17:50:55.647559Z DEBUG Connection{peer=Client}: h2::codec::framed_write: send frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
2022-04-29T17:50:55.697053Z DEBUG Connection{peer=Client}: h2::codec::framed_read: received frame=Settings { flags: (0x0), max_concurrent_streams: 100, initial_window_size: 1048576, max_header_list_size: 65536 }
2022-04-29T17:50:55.697076Z DEBUG Connection{peer=Client}: h2::codec::framed_write: send frame=Settings { flags: (0x1: ACK) }
2022-04-29T17:50:55.697087Z DEBUG Connection{peer=Client}: h2::codec::framed_read: received frame=WindowUpdate { stream_id: StreamId(0), size_increment: 983041 }
2022-04-29T17:50:55.769442Z DEBUG Connection{peer=Client}: h2::codec::framed_read: received frame=Settings { flags: (0x1: ACK) }
2022-04-29T17:50:55.769463Z DEBUG Connection{peer=Client}: h2::proto::settings: received settings ACK; applying Settings { flags: (0x0), enable_push: 0, initial_window_size: 2097152, max_frame_size: 16384 }
2022-04-29T17:50:55.847309Z DEBUG Connection{peer=Client}: h2::codec::framed_read: received frame=Headers { stream_id: StreamId(1), flags: (0x4: END_HEADERS) }
2022-04-29T17:50:55.847350Z DEBUG Connection{peer=Client}: h2::codec::framed_read: received frame=Data { stream_id: StreamId(1) }
2022-04-29T17:50:55.847375Z DEBUG Connection{peer=Client}: h2::codec::framed_read: received frame=Data { stream_id: StreamId(1), flags: (0x1: END_STREAM) }
2022-04-29T17:50:55.847388Z DEBUG Connection{peer=Client}: h2::codec::framed_read: received frame=Ping { ack: false, payload: [0, 0, 0, 0, 0, 0, 0, 0] }
2022-04-29T17:50:55.847416Z DEBUG Connection{peer=Client}: h2::codec::framed_write: send frame=Ping { ack: true, payload: [0, 0, 0, 0, 0, 0, 0, 0] }
2022-04-29T17:50:55.847755Z DEBUG Connection{peer=Client}: h2::codec::framed_write: send frame=GoAway { error_code: NO_ERROR, last_stream_id: StreamId(0) }
2022-04-29T17:50:55.847806Z DEBUG Connection{peer=Client}: h2::proto::connection: Connection::poll; connection error error=GoAway(b"", NO_ERROR, Library)
2022-04-29T17:50:57.615019Z DEBUG apollo_router::router_factory: creating plugin: 'apollo.telemetry' with configuration:
{}
2022-04-29T17:50:57.615051Z DEBUG apollo_router::router_factory: starting plugin: apollo.telemetry
2022-04-29T17:50:57.615065Z DEBUG apollo_router::plugins::telemetry: starting Spaceport
2022-04-29T17:50:57.615186Z DEBUG apollo_router::plugins::telemetry::tracing::apollo: configuring Apollo tracing
2022-04-29T17:50:57.615194Z DEBUG apollo_router::plugins::telemetry::tracing::apollo: configuring exporter to Spaceport
2022-04-29T17:50:57.615203Z DEBUG apollo_router::plugins::telemetry::tracing::apollo_telemetry: collector: https://127.0.0.1:50941/
2022-04-29T17:50:57.615209Z DEBUG apollo_router::plugins::telemetry::tracing::apollo_telemetry: graph: Some(StudioGraph { reference: "GED-Router@akarak-dev" })
2022-04-29T17:50:57.615253Z DEBUG apollo_router::router_factory: started plugin: apollo.telemetry
2022-04-29T17:50:57.861131Z DEBUG apollo_router::router_factory: activating plugin apollo_router::plugins::telemetry::Telemetry
2022-04-29T17:50:57.861203Z DEBUG apollo_router::router_factory: activated plugin apollo_router::plugins::telemetry::Telemetry
2022-04-29T17:50:57.861415Z DEBUG apollo_router::state_machine: transitioned to state running
2022-04-29T17:50:57.861443Z  INFO apollo_router: listening on http://127.0.0.1:4000 🚀
2022-04-29T17:50:58.799255Z DEBUG hyper::proto::h1::io: parsed 10 headers
2022-04-29T17:50:58.799271Z DEBUG hyper::proto::h1::conn: incoming body is content-length (76 bytes)
2022-04-29T17:50:58.799322Z DEBUG hyper::proto::h1::conn: incoming body completed
2022-04-29T17:50:58.799418Z DEBUG request{method=POST uri=/graphql version=HTTP/1.1}: tower_http::trace::on_request: started processing request
2022-04-29T17:50:58.799530Z DEBUG request{method=POST uri=/graphql version=HTTP/1.1}:graphql_request{query=query {
  vehicles(count: 1)
  {
    id
    modelCode
}
} operation_name=}: tower::buffer::worker: service.ready=true processing request
2022-04-29T17:50:58.799562Z DEBUG request{method=POST uri=/graphql version=HTTP/1.1}:graphql_request{query=query {
  vehicles(count: 1)
  {
    id
    modelCode
}
} operation_name=}: tower::buffer::worker: service.ready=true processing request
2022-04-29T17:50:58.799606Z DEBUG request{method=POST uri=/graphql version=HTTP/1.1}:graphql_request{query=query {
  vehicles(count: 1)
  {
    id
    modelCode
}
} operation_name=}: tower::buffer::worker: service.ready=true processing request
2022-04-29T17:50:58.799868Z DEBUG request{method=POST uri=/graphql version=HTTP/1.1}:graphql_request{query=query {
  vehicles(count: 1)
  {
    id
    modelCode
}
} operation_name=}: tower::buffer::worker: service.ready=true processing request
2022-04-29T17:50:58.811396Z DEBUG request{method=POST uri=/graphql version=HTTP/1.1}:graphql_request{query=query {
  vehicles(count: 1)
  {
    id
    modelCode
}
} operation_name=}: tower::buffer::worker: service.ready=true processing request
2022-04-29T17:50:58.811507Z DEBUG request{method=POST uri=/graphql version=HTTP/1.1}:graphql_request{query=query {
  vehicles(count: 1)
  {
    id
    modelCode
}
} operation_name=}:execute:fetch: tower::buffer::worker: service.ready=true processing request
2022-04-29T17:50:58.811604Z DEBUG hyper::client::connect::dns: resolving host="localhost"
2022-04-29T17:50:58.812282Z DEBUG request{method=POST uri=/graphql version=HTTP/1.1}:graphql_request{query=query {
  vehicles(count: 1)
  {
    id
    modelCode
}
} operation_name=}:execute:fetch: hyper::client::connect::http: connecting to [::1]:8090
2022-04-29T17:50:58.816990Z DEBUG request{method=POST uri=/graphql version=HTTP/1.1}:graphql_request{query=query {
  vehicles(count: 1)
  {
    id
    modelCode
}
} operation_name=}:execute:fetch: hyper::client::connect::http: connected to [::1]:8090
2022-04-29T17:50:58.817183Z DEBUG hyper::proto::h1::io: flushed 164 bytes
2022-04-29T17:50:58.819446Z DEBUG hyper::proto::h1::io: parsed 3 headers
2022-04-29T17:50:58.819472Z DEBUG hyper::proto::h1::conn: incoming body is chunked encoding
2022-04-29T17:50:58.819507Z DEBUG hyper::proto::h1::decode: incoming chunked header: 0x79 (121 bytes)
2022-04-29T17:50:58.819738Z DEBUG hyper::proto::h1::conn: incoming body completed
2022-04-29T17:50:58.819780Z DEBUG hyper::client::pool: pooling idle connection for ("http", localhost:8090)
2022-04-29T17:50:58.819956Z ERROR request{method=POST uri=/graphql version=HTTP/1.1}:graphql_request{query=query {
  vehicles(count: 1)
  {
    id
    modelCode
}
} operation_name=}:execute: apollo_router_core::query_planner: Fetch error: HTTP fetch failed from 'vehicle-details': service 'vehicle-details' response was malformed: service 'vehicle-details' response was malformed: invalid type: string "/", expected a sequence
2022-04-29T17:50:58.820048Z DEBUG request{method=POST uri=/graphql version=HTTP/1.1}:graphql_request{query=query {
  vehicles(count: 1)
  {
    id
    modelCode
}
} operation_name=}:format_response: apollo_router_core::spec::query: invalid type for data in response.
2022-04-29T17:50:58.820167Z DEBUG request{method=POST uri=/graphql version=HTTP/1.1}: tower_http::trace::on_response: finished processing request latency=20 ms status=200
2022-04-29T17:50:58.820263Z DEBUG hyper::proto::h1::io: flushed 549 bytes
^C2022-04-29T17:51:01.034315Z DEBUG apollo_router::state_machine: shutting down
2022-04-29T17:51:01.034414Z DEBUG apollo_router::state_machine: transitioned to state stopped
2022-04-29T17:51:01.034421Z DEBUG apollo_router::state_machine: stopped
2022-04-29T17:51:01.034465Z DEBUG apollo_router::plugins::telemetry: notifying spaceport to shut down
2022-04-29T17:51:01.034467Z  INFO apollo_router: stopped
2022-04-29T17:51:01.034477Z DEBUG hyper::server::shutdown: signal received, starting graceful shutdown
2022-04-29T17:51:01.034532Z DEBUG tower::buffer::worker: buffer closing; waking pending tasks
2022-04-29T17:51:01.034540Z DEBUG tower::buffer::worker: buffer closing; waking pending tasks
2022-04-29T17:51:01.034551Z DEBUG tower::buffer::worker: buffer closing; waking pending tasks
2022-04-29T17:51:01.034554Z DEBUG tower::buffer::worker: buffer closing; waking pending tasks
2022-04-29T17:51:01.034541Z DEBUG tower::buffer::worker: buffer closing; waking pending tasks
2022-04-29T17:51:01.034542Z DEBUG tower::buffer::worker: buffer closing; waking pending tasks
2022-04-29T17:51:01.034542Z DEBUG tower::buffer::worker: buffer closing; waking pending tasks
2022-04-29T17:51:01.034563Z DEBUG tower::buffer::worker: buffer closing; waking pending tasks
2022-04-29T17:51:01.034537Z DEBUG tower::buffer::worker: buffer closing; waking pending tasks
2022-04-29T17:51:01.034533Z DEBUG tower::buffer::worker: buffer closing; waking pending tasks

atanuk avatar Apr 29 '22 18:04 atanuk

Hello @atanuk could you show us a part of your supergraph schema ? Especially the part about vehicles ? Also a part of the subgraph schema might be useful to understand.

bnjjj avatar May 03 '22 13:05 bnjjj

@atanuk Do you have any updates on this?

abernix avatar May 17 '22 11:05 abernix

Here is the subgraph schema given below.

type Vehicle {
	id: ID!,
	type: String,
	modelCode: String,
	brandName: String,
	launchDate: String
}

type Query {
	vehicles(count: Int):[Vehicle]
	vehicle(id: ID):Vehicle
}

type Mutation {
	createVehicle(type: String!, modelCode: String!, brandName: String, launchDate: String):Vehicle
}

And part of supergraph schema given below.

enum join__Graph {
...
  VEHICLE_DETAILS @join__graph(name: "vehicle-details", url: "http://localhost:8090/")
}

type Query
  ...
  @join__type(graph: VEHICLE_DETAILS)
{
  ...
  vehicles(count: Int): [Vehicle] @join__field(graph: VEHICLE_DETAILS)
  vehicle(id: ID): Vehicle @join__field(graph: VEHICLE_DETAILS)
}

type Vehicle
  @join__type(graph: VEHICLE_DETAILS)
{
  id: ID!
  type: String
  modelCode: String
  brandName: String
  launchDate: String
}

atanuk avatar May 17 '22 16:05 atanuk

@atanuk Sorry for the delay I missed the notification. I tried to reproduce locally with exactly the same schema and the same data returned by the subgraph and it's working. Maybe we fixed it in one of our release. Do you still have this issue ?

bnjjj avatar Aug 02 '22 09:08 bnjjj

I'll close this since we haven't heard back from you, but happy to reopen if you're still experiencing the problem! Thanks for opening this originally!

abernix avatar Aug 30 '22 10:08 abernix