Cache normalization silently failing and clearing cache with Cyclical Mutation response

[Nealsoni00]

I'm reporting a mutation that changes the cache of an initial query of an entity. The entity is identified by a globaly unique UUID id string. However, the query listener for that is listening for changes to the entity gets called with empty data. Inspecting the cache for the query in the callback also returns empty data.

Mutation performed:

   final eventReportM = GEventReportReq((b) => b
      ..vars.alertTypeId = alertTypeId
      ..vars.entityId = entityId);

    graphQLClient.request(eventReportM).listen((response) {
        final entity = response.data?.eventReport?.event.entity;
        print("MUTATION GOT RESPONSE ENTITY (${entity})"); // <-- Returns new entity (with passed entity id)
    });

Widget Watching for the change to entity

class EventTabState extends State<EventTab> {
  @override
  void initState() {
    final currEntityReq =
        GFetchCurrentEntityReq((b) => b..fetchPolicy = FetchPolicy.CacheFirst);

    graphQLClient
        .request(currEntityReq)
        .listen((response) async {
      print( "CURRENT ENTITY IN EVENT TAB: ${response.dataSource} | ${response.data}");
      print("CURRENT ENTITY IN EVENT TAB ERRORS: ${response.hasErrors} --> ${response.linkException} ${response.graphqlErrors}");
      final data = application.state.graphQLClient.cache.readQuery(currEntityReq);
      print("CURRENT ENTITY FROM CACHE IN EVENT TAB: ${data}");
    });

    super.initState();
  }

What is printed to the console:

# initState() called with previous query data fetched on app launch

I/flutter ( 9982): CURRENT ENTITY IN EVENT TAB: DataSource.Cache | GFetchCurrentEntityData {
I/flutter ( 9982):   G__typename=Query,
I/flutter ( 9982):   currentEntity=GFetchCurrentEntityData_currentEntity {
I/flutter ( 9982):     G__typename=Entity,
I/flutter ( 9982):     id=3d27968f-fa2c-42ce-9e39-17341b6e9c76,  # <-- Note ID
I/flutter ( 9982):     appState=report, # <-- Original State
I/flutter ( 9982):     entityState=report,  # <-- Original State
I/flutter ( 9982):     entityStateDescription=Normal  # <-- Original State
I/flutter ( 9982):   },
I/flutter ( 9982): }
I/flutter ( 9982): CURRENT ENTITY IN EVENT TAB ERRORS: false --> null null
I/flutter ( 9982): CURRENT ENTITY FROM CACHE IN EVENT TAB: GFetchCurrentEntityData {
I/flutter ( 9982):   G__typename=Query,
I/flutter ( 9982):   currentEntity=GFetchCurrentEntityData_currentEntity {
I/flutter ( 9982):     G__typename=Entity,
I/flutter ( 9982):     id=3d27968f-fa2c-42ce-9e39-17341b6e9c76, # <-- Note ID
I/flutter ( 9982):     appState=report, # <-- Original State
I/flutter ( 9982):     entityState=report, # <-- Original State
I/flutter ( 9982):     entityStateDescription=Normal  # <-- Original State
I/flutter ( 9982):   },
I/flutter ( 9982): }

# Reporting the event -- getting new entity in response

I/flutter ( 9982): REPORTING AN EVENT!! ca6eaec6-adac-4030-81c9-256a57cd9ab0 3d27968f-fa2c-42ce-9e39-17341b6e9c76
I/flutter ( 9982): MUTATION GOT RESPONSE ENTITY (GEmergencyReportData_eventReport_event_entity {
I/flutter ( 9982):   G__typename=Entity,
I/flutter ( 9982):   id=3d27968f-fa2c-42ce-9e39-17341b6e9c76, # <-- Same ID
I/flutter ( 9982):   appState=event, # <-- Changed property
I/flutter ( 9982):   entityState=confirm, # <-- Changed property
I/flutter ( 9982):   entityStateDescription=Event Reported,  # <-- Changed property
I/flutter ( 9982):   },
I/flutter ( 9982): }

# Current Entity Listener called 

I/flutter ( 9982): CURRENT ENTITY IN EVENT TAB: DataSource.Cache | null   # <-- Query Response Empty
I/flutter ( 9982): CURRENT ENTITY IN EVENT TAB ERRORS: false --> null null # <-- No Errors
I/flutter ( 9982): CURRENT ENTITY FROM CACHE IN EVENT TAB: null # <-- Cache for Query Empty

# User listener being called with proper data

I/flutter ( 9982): USER APP DATA DataSource.Cache | User Name # Another query listener that depending on Entity ID being called but it never asked originally for the property that changed (appState). 

UPDATE: Seems that when the Current Entity Listener is called, response.loading is true and never gets called when loading is completed.

[smkhalsa]

Please provide a repro or a failing test. It's difficult to provide any insight with the partial context provided.

[darkfrog26]

It seems to me that there are two serious problems here apart from a potential problem with the developer code: 1.) The fact that something can occur in an update that causes the entity in the cache to be nullified seems like a scary bug in Ferry. 2.) The fact that something is obviously going wrong in the internals of the code of Ferry that cause (1) to happen, and yet, the error seems to be swallowed and nothing being logged is also very concerning.

[Nealsoni00]

After debugging more, I have found a single small change that results in the same issue I described above:

Watching this returns the cache data successfully:

query FetchCurrentEntity {
    currentEntity {  # Object
        id
        activeEvents { # Array
            id
        }
    }

Watching this returns the cache as null with infinate loading

query FetchCurrentEntity {
    currentEntity {  # Object
        id
        activeEvents { # Array
            id
            initialAnnouncement { # Object
                id
            }
        }
    }

When the array starts off as empty, and the mutation returns the Entity with an array of Event objects with their own nested object (initialAnnouncement), it clears the query cache and fails silently.

A hard reload fetching the same data with FetchCurrentEntity succeeds.

I am thinking it is due to the merging of the data failing and that error not being propagated to the watcher.

[Nealsoni00]

This seems to be the issue -- on cache normalization (merging) the mutation returns the same event object:

This mutation calls the query watcher with null data

mutation EventReport($alertTypeId: ID!, $entityId: ID!) {
    eventReport(input: { alertTypeId: $alertTypeId, entityId: $entityId }) {
        event {
            id # <-- THIS ID IS SAME 
            entity { <-- Sub property for event
                id
                activeEvents {
                    id # <-- THIS ID IS SAME
                    initialAnnouncement { <-- sub property for event
                        id
                    }
                }
            }
        }
    }
}

This one calls the query watcher CORRECTLY!

mutation EventReport($alertTypeId: ID!, $entityId: ID!) {
    eventReport(input: { alertTypeId: $alertTypeId, entityId: $entityId }) {
        event {
            id # <-- THIS ID IS SAME 
            initialAnnouncement {
              id
            }
            entity {
                id
                activeEvents {
                    id # <-- THIS ID IS SAME
                }
            }
        }
    }
}

I think the error is that the cached data is not merged properly if a type with the same ID is returned with two different sets of sub-properties. In the top case, this happens where event has a entity and activeEvents has an initialAnnouncement. Thus, when I check the recursive merge process in normalize the merged data starts from the inside activeEvents, it assigns the initialAnnouncement. However, when it gets to the outer event, it gets replaced with just the entity entity property.

Only the differing sub-objects cause the query-cache nulling error, differing inner properties like a boolean do not cause the watcher to null out but the inner-most data is still lost.

[Nealsoni00]

Example logging of the recursive merging missing a property from the inner object with the same ID.

flutter: Merged Data: {__typename: Event, id: af054dd4-2e11-4463-878d-276d7af2e4ac, **active: true**} # Note the active
flutter: Merged Data: {__typename: School, id: 3d27968f-fa2c-42ce-9e39-17341b6e9c76, activeEvents: [{$ref: Event:af054dd4-2e11-4463-878d-276d7af2e4ac}]}
flutter: Merged Data: {__typename: Event, id: af054dd4-2e11-4463-878d-276d7af2e4ac, **initialAnnouncement**: {$ref: Announcement:f7a447a5-0f4d-45b6-9099-4b0ad07ae0bd}, Entity: {$ref: Entity:3d27968f-fa2c-42ce-9e39-17341b6e9c76}} # <-- Note the missing active property in this final merge that is returned
flutter: Merged Data: {__typename: EventReportPayload, event: {$ref: Event:af054dd4-2e11-4463-878d-276d7af2e4ac}}

mutation EventReport($alertTypeId: ID!, $schoolId: ID!) {
   eventReport(input: { alertTypeId: $alertTypeId, entityId: $entityId }) {
        emergency {
            id # <-- THIS ID IS SAME 
            initialAnnouncement {
              id
            }
            entity {
                id
                activeEvents {
                    id # <-- THIS ID IS SAME
                    active # This property is lost
                }
            }
        }
    }
}

[Nealsoni00]

Note -- this problem does not exist on any of the Apollo clients we used prior to migrating to flutter -- apollo-ios, apollo-android, and apollo-js. graphql_ferry has a very similar issue which is why we switched to ferry. Might be useful to explore what apollo does different in the normalization process.