Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

[v4] Both result data and exception are sometimes null on network result #747

Closed
Zony-Zhao opened this issue Oct 18, 2020 · 32 comments · Fixed by #754
Closed

[v4] Both result data and exception are sometimes null on network result #747

Zony-Zhao opened this issue Oct 18, 2020 · 32 comments · Fixed by #754
Assignees
Labels
🐛 bug Something isn't working ⌛ reproduction needed Issue is subtle and requires a true accessible reproduction to debug released v4 Issue with a v4 library

Comments

@Zony-Zhao
Copy link

Zony-Zhao commented Oct 18, 2020

Describe the bug
Just upgraded to graphql_flutter: ^4.0.0-beta.3. What I did is a normal query as I did before.

I'm not sure what is the problem.

query {
  userByToken {
    newOrders(query: {skip: 0, sortBy: "createdAt", order: 1}) {
      id
      dishMetas {
        dish {
          id
          name
          store {
            id
            name
            description
            avatar
            district {
              name
            }
          }
          tag
          price
          avatar
        }
        quantity
        remark
      }
      status
      initiator {
        id
        name
        tel
        address
      }
      deliverPrice
      createdAt
    }
  }
}

I do the same query in postman which is all fine.
I wonder in what situation this data would be null? isLoading is false, and there is no exception. Having worked on it for hours and have no clue.

@Zony-Zhao
Copy link
Author

I'm not sure using variable in resolved field is permitted or not, and encouraged or not. But when I change the endpoint to use variable at start. Everything goes well.

@Zony-Zhao Zony-Zhao reopened this Oct 20, 2020
@Zony-Zhao
Copy link
Author

Zony-Zhao commented Oct 20, 2020 via email

@jmysliv
Copy link

jmysliv commented Oct 20, 2020

I had similar issue to yours, the query result data and exception was null, but query worked fine in graphql playground. The difference was that some queries that was written earlier worked fine in my flutter app, only the new queries I added had that issue. I deleted comment, because problem "magically" disappear, after I restarted app few times, without any change in code. When I find out what was causing the problem I'll post it here.

@Zony-Zhao
Copy link
Author

I'm not that lucky as you. I restarted IDE and invalidate cache. Even restart the PC. didn't work.
I solved it by change mygraphql query and backend resolver.
As far as I guess, I think maybe something with network or cache.

@micimize
Copy link
Collaborator

Sorry to hear you beat your head on the wall here for so long – it is likely this is due to #744. Can you add:

  • your client, cache, and link declarations
  • the QueryOptions / if you using the gql helper function from graphql_flutter
  • the returned data from postman

Also try with FetchPolicy.noCache to see if you get the same data as postman.

Basically, what I think is probably happening here is that the returned structure is somehow slightly unexpected, so the write/read loop on the response data results in null due to invalid structure.

@micimize micimize changed the title result.data is null. [v4] Both result data and exception are null on network result Oct 20, 2020
@micimize micimize added 🐛 bug Something isn't working v4 Issue with a v4 library labels Oct 20, 2020
@micimize micimize self-assigned this Oct 20, 2020
@micimize micimize pinned this issue Oct 20, 2020
@micimize
Copy link
Collaborator

Details I added in the discord:

...There is likely some mismatch between the requested document structure and result, but it is unexpected behavior. The following should always pass:

assert(
  !(result.data == null && result.exception == null && result.source == QueryResultSource.network),
  'network results should always have either data or an exception, but $result has neither. '
  'This may be caused by a malformed response or cache misconfiguration.'
);

...Should have time to solve this later this week.

@jmysliv
Copy link

jmysliv commented Oct 21, 2020

@micimize
Here's my client cache and link declaration:

String typenameDataIdFromObject(Object object) {
  if (object is Map<String, Object> &&
      object.containsKey('__typename') &&
      object.containsKey('id'))
    return "${object['__typename']}/${object['id']}";
  return null;
}
  final url = DotEnv().env["GRAPHQL_URL"];
  final HttpLink httpLink = HttpLink(url);

  final AuthLink authLink = AuthLink(getToken: () async {
    final token = await TokenService.getToken();
    return '$token';
  });

  final Link link = authLink.concat(httpLink);

  ValueNotifier<GraphQLClient> client = ValueNotifier(GraphQLClient(
    cache: GraphQLCache(
      dataIdFromObject: typenameDataIdFromObject,
    ),
    link: link,
  ));

  GraphqlClientService(client: client);

here's my query and QueryOptions:

final friendsList = gql(r'''
 query FriendsList {
  me {
    friends {
      __typename
      id
      name
      email
      age
      favoriteAlcoholName
      favoriteAlcoholType
      description
      gender
      genderPreference
      alcoholPreference
      agePreferenceFrom
      agePreferenceTo
      latestLocation {
        latitude
        longitude
      }
    }

  }
}
''');
  final WatchQueryOptions options = WatchQueryOptions(
        document: query.friendsList,
        fetchResults: true,
        fetchPolicy:
            fetchCache ? FetchPolicy.cacheFirst : FetchPolicy.networkOnly); //fetchCache is set to false

    final queryResult = await client.value.query(options);
    checkQueryResultForErrors(queryResult); //checks if queryResult has exceptions if it has, our custom exception is thrown
    print(queryResult.data);
    print(queryResult.exception);
    print(queryResult.source);

I'm pretty sure that my backend works fine because when I run the same query in graphql playground it works fine and I get the following json as a result:

{
  "data": {
    "me": {
      "friends": []
    }
  }
}

However when I run my flutter app that query works randomly, sometimes it fetches result properly, but more often both the result data and exceptions is null and source is network. Sometimes restarting app helps but not always.

@micimize
Copy link
Collaborator

@jmysliv thanks for the info – the fact that it's inconsistent is even more troubling than it just not working. Does it ever have friends data? Also, try this in the playground and see if __typenames are added in the result:

query FriendsList {
  __typename
  me {
    __typename
    friends {
      __typename
      id
      name
    }
  }
}

@jmysliv
Copy link

jmysliv commented Oct 21, 2020

@micimize thanks for reply. Yes, but I was testing without any friends added. Here's result for your query when I added friend in the database.

{
  "data": {
    "__typename": "Query",
    "me": {
      "__typename": "Account",
      "friends": [
        {
          "__typename": "Account",
          "id": "6512afe0-c173-4d66-b803-57891fb3172e",
          "name": "kuba"
        }
      ]
    }
  }
}

@jmysliv
Copy link

jmysliv commented Oct 21, 2020

Okay, I think I found source of the problem. I tried your query inside my flutter app and it started working. The same result I achieved when I commented code inside this function (it returns null all the time).

String typenameDataIdFromObject(Object object) {
  // if (object is Map<String, Object> &&
  //     object.containsKey('__typename') &&
  //     object.containsKey('id'))
  //   return "${object['__typename']}/${object['id']}";
  return null;
}

I think there is some problem with cache when there isn't __typename field in the query result. However it's quite weird cause I'm checking in this function if object contains __typename field and return null when it doesn't. What's more problem occurs even when my FetchPolicy is set to NetworkOnly, so cache shouldn't be used at all in that case but it seems that it is used. Adding __typename on every level of nested query solves the problem, but I still think that something is not working like it should. Still, thanks for help!

@Zony-Zhao
Copy link
Author

While @jmysliv is using the stable version, I 'm using
image
And my client
image

@micimize
Copy link
Collaborator

micimize commented Oct 24, 2020

@Zony-Zhao and @jmysliv I made a PR that should hopefully provide more info on what's going on here – try running your queries with the following to see if it gives more fruitful errors:

dependency_overrides:
  graphql:
    git: 
      url: git@github.com:micimize/graphql-flutter.git
      ref: norm_data_handling
      path: packages/graphql
  normalize:
    git: 
      url: git@github.com:micimize/ferry.git
      ref: partial_paths
      path: normalize

@jmysliv
Copy link

jmysliv commented Oct 26, 2020

@micimize Seems that nothing changed cause I get the following query result after I run my previous code with the dependency override:

QueryResult(source: QueryResultSource.network, data: null, exception: null, timestamp: 2020-10-26 22:04:16.678639)

However as I write before, when I added __typename field to my query it started work fine so I don't get any errors now.

@micimize micimize changed the title [v4] Both result data and exception are null on network result [v4] Both result data and exception are sometimes null on network result Oct 27, 2020
@SanjiKir
Copy link

@micimize I probably will join this issue because I was trying to hunt the bug in my app as well, I thought there is some issue with rebroadcasting, but apparently, I have the same problem as 2 guys above. To shortly describe in mutation on update I am writing newly created data to cache, however sometimes, absolutely randomly they are not written. I was trying to replicate this bug for months now and I've just seen this issue. The worst thing is that our customers sometimes complain about it as well :( Hopefully, that will be fixed soon!

@SanjiKir
Copy link

Okay, small update. I've made a condition in update function if (result.data == null) { return; } and I've made a breakpoint there. Then I managed to replicate the bug, however, the breakpoint didn't work (meaning data was not null). I've also inspected the cache and I don't see a newly created item in there, possibly the problem lies in cache.writeQuery. I hope this helps somehow.

@micimize
Copy link
Collaborator

@SanjiKir if you reproduce again with these overrides, does writeQuery throw an error? Either way, what is the query + data that sometimes throws and sometimes doesn't? We need to establish a failing test case, and figure out if it's due to an unexpected data structure or a race condition or what.

dependency_overrides:
  graphql:
    git: 
      url: git@github.com:micimize/graphql-flutter.git
      ref: norm_data_handling
      path: packages/graphql
  normalize:
    git: 
      url: git@github.com:micimize/ferry.git
      ref: partial_paths
      path: normalize

@micimize
Copy link
Collaborator

I'm really perplexed by this issue, and can't seem to find a solid test case / hypothesis for when this happens, but given the current behavior description of "sometimes writeQuery/readQuery fails it could be multiple issues.

Anyone running in to this please test with a clean cache and the above overrides, and record a sequence of cache that can create the write/read round-trip failure. It is possible that someone might be running in to gql-dart/ferry#98, or that #754 solves the issue in some cases but not all, but we need data that can be turned into an actual test case.

@SanjiKir
Copy link

SanjiKir commented Nov 1, 2020

@micimize I will give it a shot, today or tomorrow. Pinky swear :D Just to clarify things, in case this thing occurs again instead of silently failing it should throw an error, right?

@micimize
Copy link
Collaborator

micimize commented Nov 1, 2020

@SanjiKir yes – in fact you prompted me to add the following in the event of non-structural roundtrip cache failures:

If write succeeds but readQuery then returns null, a CacheMissException will be added and the data will not be overwritten

@micimize micimize added the ⌛ reproduction needed Issue is subtle and requires a true accessible reproduction to debug label Nov 6, 2020
@micimize
Copy link
Collaborator

micimize commented Nov 6, 2020

merged #754, but I am not confident it solves whatever is happening here. Regardless, please add partialDataPolicy: PartialDataCachePolicy.reject to your cache options when using the latest there.

@micimize
Copy link
Collaborator

@Zony-Zhao this looks like an entirely different possible issue. Either the client is not adding the error to the exception for some reason, or you aren't checking for result.hasException before attempting to access result.data['userByToken']. In this particular case, result.data == null should be true

@Zony-Zhao
Copy link
Author

Yeah,My bad. This is another thing. I'll delete the post in case of misdirecting others.

@SanjiKir
Copy link

@micimize Extremely sorry for breaking my pinky swear, but I just managed to test it. So I bumped to v4.beta.5 added

partialDataPolicy: PartialDataCachePolicy.reject

And duplicated the bug. The update was no written to the cache, yet I didn't see any error.

Also I am not 100% sure, but I believe this problem was in v3 as well when I was using old options to write to the cache.

@SanjiKir
Copy link

SanjiKir commented Nov 17, 2020

@micimize Okay update.

I debugged it from all ends. What I've noticed, is that update method randomly returns the wrong result from the server. To be more specific I am creating an entity called order. In update I expect the result from the server and I want to write it to the cache, so it will be rebroadcasted and showed immediately. However update method of CreateOrderMutation returns an absolutely different order. Well, I was like, **** we screwed up on the back-end. But, no! I debugged it locally on the BE and in the Flutter app, BE returns the correct result from the endpoint, however, update method ends up with absolutely wrong result.

Do you have any ideas what can be wrong?

@micimize
Copy link
Collaborator

@SanjiKir

  • do you mean that in update, when result.source is network, result.data of the QueryResult passed to Mutation.update contains the data for the previous CreateOrderMutation?
  • what are some concrete examples of the operation, variables, and result data here?
  • is there anything else happening in the app at the same time, like are multiple CreateOrderMutations happening at once?

Actual code excepts are invaluable here. Maybe:

  • there's a race condition
  • or update is somehow getting a stale result in place of an optimistic one before the network response has been received
  • or the writeQuery -> readQuery roundtrip is overwriting all the data with optimistic results from elsewhere because of some normalization issue __typename / id are the same between two instances of the same mutation

@FickleLife
Copy link

FickleLife commented Nov 19, 2020

I just stumbled across this error, adding some more info here which might help diagnose. My query is:

query BarcodeScanLog($limit: Int = 50) {
  barcodeScanLog(limit: $limit) {
    __typename
    createdAt
    product {
      __typename
      id
      name
      brand {
        __typename
        name
      }
    }
  }
}

I was getting NoSuchMethodError: The method '[]' was called on null.. To resolve, I had to pass a variable for limit instead of relying on the default in the query. I'm on graphql_flutter: ^4.0.0-beta.3

@micimize
Copy link
Collaborator

@FickleLife the fact that the variable made a difference is noteworthy, but based on what you're saying it isn't necessarily the same issue:

  • what was the complete stacktrace?
  • where was the error thrown – in update?
  • What is the result.source & expected data? Is result.data null?
  • Does it fail consistently, or only after a second attempt?

@SanjiKir
Copy link

SanjiKir commented Nov 21, 2020

@SanjiKir

  • do you mean that in update, when result.source is network, result.data of the QueryResult passed to Mutation.update contains the data for the previous CreateOrderMutation?

Not sure about the previous one, the funny thing it's actually related to the entity the order is being placed on. So Order has always a place, right. And in update the wrong order is always from the same place. Everything else you said seems to be accurate.

  • what are some concrete examples of the operation, variables, and result data here?

mutation

mutation CreateOrder($placeId: ID!, $lines: [OrderLineCreate!]!, $name: String) {
  createOrder(data: {
    placeId: $placeId
    lines: $lines
    name: $name
  }){
    ...orderFields
  }
}

Fragment

fragment orderFields on Order {
    __typename
    id
    createdUtc
    updatedUtc
    orderState
    name
    orderNumber
      place {
        __typename
        id
        name
      }
      orderLines {
        __typename
        id
        price
        quantity
        unitPrice
        orderLineState
        createdUtc
        product {
          __typename
          id
          name
          priceSell
          printingDeviceId
        }
      }
}

Result data correct

 {__typename: Order, id: f2b4f257-350a-4d9e-9a02-c3c1dd4add56, createdUtc: 1605999494381, updatedUtc: 1605999494381, orderState: Opened, name: null, orderNumber: MY2020000019, place: {__typename: Place, id: 9b406059-a85f-4ffd-ae3d-89821fb73cbc, name: Bar 3}, orderLines: [{__typename: OrderLine, id: be2c59d8-3721-4adf-be70-34a4af4703ac, price: 5000, quantity: 1, unitPrice: 5000, orderLineState: Opened, createdUtc: 1605999494381, product: {__typename: Product, id: 52f23a2c-c4b5-4e27-90ba-d6b24a354a1b, name: Red label glass, priceSell: 5000, printingDeviceId: 92a33c80-5285-4c6c-88aa-2222fe6f373d}}]}

Result data wrong

{__typename: Order, id: 5e74a8c8-6724-4a07-aeb7-c0670e78e98e, createdUtc: 1605998577724, updatedUtc: 1605998625731, orderState: Closed, name: null, orderNumber: MY2020000005, place: {__typename: Place, id: 9b406059-a85f-4ffd-ae3d-89821fb73cbc, name: Bar 3}, orderLines: [{__typename: OrderLine, id: 006bce75-0154-4929-8071-86a29b2d5e6c, price: 5000, quantity: 1, unitPrice: 5000, orderLineState: Paid, createdUtc: 1605998577724, product: {__typename: Product, id: 52f23a2c-c4b5-4e27-90ba-d6b24a354a1b, name: Red label glass, priceSell: 5000, printingDeviceId: 92a33c80-5285-4c6c-88aa-2222fe6f373d}}]}

Notice that the place is the same, however order state is closed. Meaning this order was created and closed earlier and now we've tried to create a new one, however both update and onCompleted returned the old order.

  • is there anything else happening in the app at the same time, like are multiple CreateOrderMutations happening at once?

No, no race conditions, no multiple order creations, nothing like that.

Actual code excepts are invaluable here. Maybe:

  • there's a race condition

No race condition, no mutation are running

  • or update is somehow getting a stale result in place of an optimistic one before the network response has been received

We don't use optimistim so far

  • or the writeQuery -> readQuery roundtrip is overwriting all the data with optimistic results from elsewhere because of some normalization issue __typename / id are the same between two instances of the same mutation

This I am not sure I understand, if you can elaborate I can do a double check. We do not provide a custom function for normalization, which means we use the default one.

cc @micimize

micimize added a commit that referenced this issue Nov 22, 2020
@micimize
Copy link
Collaborator

@SanjiKir Thanks for the details – on the last item if you aren't using optimisticResult at all then it can't be that.

I've made a branch and added a test and data for investigating this issue, but have still not had any luck actually reproducing:
https://github.com/zino-app/graphql-flutter/blob/d20d061fa2309636b1a9827dbc1b89e26605b45e/packages/graphql/test/graphql_client_test.dart#L434-L435

pub run test test/graphql_client_test.dart -n 'watchQuery mutations are isolated'

It is rather perplexing. That the cache write has to both fail silently, and then succeed to read an old value, implies either that something is critically wrong (i.e. hive somehow fails puts occasionally), or there's some wacky error, like a custom CreateOrderVariables object with a toJson() that returns the correct variables only once, then null afterwards. In other words, I still have no idea why this is happening

@SanjiKir
Copy link

SanjiKir commented Nov 23, 2020

@micimize Okay I started debugging graphql lib now to solve this problem. What I've found out that it tries to eagerly resolve it from cache (see image), because mutation have default cache and network policy. Now I am not 100% sure, but my guess is since we do not provide id for lines it resolves the latest case of this mutation using the placeId and the productId. So to reproduce it we have to:

  1. Create an order assign place and orderlines to it.
  2. Close the order
  3. Create the exact same order on the same place
  4. Now after we create graphql returns the old order which we already closed because place and OL are the same.

Now I am not sure this is actually correct behavior, it's probably done for optimism, right? Any ideas on how can I fix it besides using networkOnly?
image

@micimize
Copy link
Collaborator

@SanjiKir ohhhh ok, we finally have an answer to what's going on. So, actually I would recommend using networkOnly for now.

Here's what's happening: The default policy for client.watchQuery is cacheAndNetwork, but that is actually a bad default policy for mutations, which is why the default policy for client.mutate is networkOnly. However, because we use watchQuery for the Mutation widget (because we have no watchMutation), you automatically get the last result of the mutation with the same variables from the cache, which is probably what made it seem random.

This is a serious issue, but different from this one. Here're more details on exactly what's happening.

Am closing this in favor of #774

@micimize micimize unpinned this issue Nov 23, 2020
micimize added a commit to micimize/graphql-flutter that referenced this issue Jan 20, 2021
@HofmannZ
Copy link
Member

🎉 This issue has been resolved in version 4.0.0 🎉

The release is available on GitHub release

Your semantic-release bot 📦🚀

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
🐛 bug Something isn't working ⌛ reproduction needed Issue is subtle and requires a true accessible reproduction to debug released v4 Issue with a v4 library
Projects
None yet
Development

Successfully merging a pull request may close this issue.

6 participants