App icon indicating copy to clipboard operation
App copied to clipboard

[$250] Chat - Group is created with duplicate user when chat is started quickly on a slow network

Open lanitochka17 opened this issue 1 year ago • 49 comments

If you haven’t already, check out our contributing guidelines for onboarding and email [email protected] to request to join our Slack channel!


Version Number: 9.0.41-2 Reproducible in staging?: Y Reproducible in production?: Y If this was caught during regression testing, add the test name, ID and link from TestRail: N/A Email or phone of affected tester (no customers): [email protected] Issue reported by: Applause - Internal Team

Action Performed:

  1. Go to https://staging.new.expensify.com/.
  2. Open the Developer Tools and go to the Network tab, then set the network speed to 3G
  3. Click on the FAB > Start Chat
  4. Enter a user's email, then quickly click on it before the fallback avatar changes to the correct user avatar
  5. Send a message

Expected Result:

The chat with the selected user should remain a 1-on-1 chat. The chat should not change into a group with duplicate users

Actual Result:

After sending the message, the chat turns into a group with duplicate users. It only corrects itself back to a single chat after switching to another chat and then returning to it

Workaround:

Unknown

Platforms:

Which of our officially supported platforms is this issue occurring on?

  • [ ] Android: Native
  • [ ] Android: mWeb Chrome
  • [ ] iOS: Native
  • [ ] iOS: mWeb Safari
  • [x] MacOS: Chrome / Safari
  • [ ] MacOS: Desktop

Screenshots/Videos

Add any screenshot/video evidence

https://github.com/user-attachments/assets/7ed99952-55d7-44f6-a72f-26f59e044154

View all open jobs on GitHub

Upwork Automation - Do Not Edit
  • Upwork Job URL: https://www.upwork.com/jobs/~021843049310841478139
  • Upwork Job ID: 1843049310841478139
  • Last Price Increase: 2024-10-13
  • Automatic offers:
    • DylanDylann | Contributor | 104420901
    • nkdengineer | Contributor | 104651259
Issue OwnerCurrent Issue Owner: @nkdengineer

lanitochka17 avatar Sep 30 '24 13:09 lanitochka17

Triggered auto assignment to @RachCHopkins (Bug), see https://stackoverflow.com/c/expensify/questions/14418 for more details. Please add this bug to a GH project, as outlined in the SO.

melvin-bot[bot] avatar Sep 30 '24 13:09 melvin-bot[bot]

I don't understand what's happening in that video. I can't replicate this.

image

I'm on 2 bars of 4G.

Is the person reporting it saying that the two users other than themselves are, in fact, the same user?

RachCHopkins avatar Oct 01 '24 01:10 RachCHopkins

Please clarify the "actual result"

RachCHopkins avatar Oct 01 '24 01:10 RachCHopkins

Waiting on a response/clarification from QA team.

RachCHopkins avatar Oct 04 '24 05:10 RachCHopkins

team is still able to reproduce

https://github.com/user-attachments/assets/44e432c6-24e5-4553-abba-0aab81c6dcb9

mvtglobally avatar Oct 04 '24 13:10 mvtglobally

Ok, to sum up, it can be reproduced and we don't know what/who the third user is.

RachCHopkins avatar Oct 06 '24 22:10 RachCHopkins

Job added to Upwork: https://www.upwork.com/jobs/~021843049310841478139

melvin-bot[bot] avatar Oct 06 '24 22:10 melvin-bot[bot]

Triggered auto assignment to Contributor-plus team member for initial proposal review - @parasharrajat (External)

melvin-bot[bot] avatar Oct 06 '24 22:10 melvin-bot[bot]

Edited by proposal-police: This proposal was edited at 2024-10-07T12:12:00Z.

Proposal

Please re-state the problem that we are trying to solve in this issue.

After sending the message, the chat turns into a group with duplicate users. It only corrects itself back to a single chat after switching to another chat and then returning to it

What is the root cause of that problem?

When OpenReport API is called, the success data is added to queuedOnyxUpdates and waited for all write requests to be complete before merging it to Onyx

https://github.com/Expensify/App/blob/04214cdb3e35816fd28a640f1b3c1b23bd7407b0/src/libs/actions/QueuedOnyxUpdates.ts#L11-L15

We've had the logic to flush the queue after all requests are complete here

https://github.com/Expensify/App/blob/04214cdb3e35816fd28a640f1b3c1b23bd7407b0/src/libs/Network/SequentialQueue.ts#L172-L174

But in this case after AddComment API is called, the queue is paused

https://github.com/Expensify/App/blob/04214cdb3e35816fd28a640f1b3c1b23bd7407b0/src/libs/actions/OnyxUpdates.ts#L147-L153

After GetMissingOnyxMessages API, the queue is active again but the queue is empty then the queuedOnyxUpdates isn't flush which causes the participant of the DM to have both optimistic and current participants of a user.

What changes do you think we should make in order to solve the problem?

  • In unpause function, we should flush the queuedOnyxUpdates if there is no request . We should update after this line.

I notice that we should only flush the queuedOnyxUpdates if only numberOfPersistedRequests is 0 because if we merge these data to Onyx when there are some pending requests in the queue that can cause the race condition since other requests can update the data for the same key of the previous request.

if (numberOfPersistedRequests === 0) {
    flushOnyxUpdatesQueue();
}

https://github.com/Expensify/App/blob/04214cdb3e35816fd28a640f1b3c1b23bd7407b0/src/libs/Network/SequentialQueue.ts#L192

  • For the reason why GetMissingOnyxMessages API is called I think maybe it's expected from BE. But after all, the frontend problem can happen in other cases and we need to fix this and it also fixes this issue.

What alternative solutions did you explore? (Optional)

nkdengineer avatar Oct 07 '24 05:10 nkdengineer

Proposal

Please re-state the problem that we are trying to solve in this issue.

On slow networks, if we create a report and comment on it, a group with a duplicate chat is created.

What is the root cause of that problem?

For write requests, we do not write the response onyxData and the corresponding successData/failureData/finallyData to Onyx directly. Instead, we write them to queuedOnyxUpdates to prevent the replay effect. https://github.com/Expensify/App/blob/78e484f41e5fb5fa3f8827d2b4aea0ba55b581e4/src/libs/actions/OnyxUpdates.ts#L30-L32 These updates are flushed only after all the PersistedRequests are cleared. https://github.com/Expensify/App/blob/78e484f41e5fb5fa3f8827d2b4aea0ba55b581e4/src/libs/Network/SequentialQueue.ts#L173-L175 We remove a request from persistent requests only after the response is received and processed with all middlewares. https://github.com/Expensify/App/blob/78e484f41e5fb5fa3f8827d2b4aea0ba55b581e4/src/libs/Network/SequentialQueue.ts#L90-L99 So, on slow networks, when we call OpenReport, its response and corresponding request’s successData, etc., are added to queuedOnyxUpdates. This cannot be flushed immediately because there was already an AddComment request added to the PersistedRequests. For some reason that needs to be fixed, the backend sends a previousUpdateID for AddComment that is larger than the previous lastUpdateID/lastClientUpdateID. This makes doesClientNeedToBeUpdated true. https://github.com/Expensify/App/blob/78e484f41e5fb5fa3f8827d2b4aea0ba55b581e4/src/libs/Middleware/SaveResponseInOnyx.ts#L34 As a result, the AddComment response is not processed directly with OnyxUpdates.apply. It sets this AddComment response to saveUpdateInformation, and the queue is paused. When the queue is paused, the updates waiting in queuedUpdates are not flushed, so OpenReport’s successData waits in the queuedUpdates, and the optimistic user detail is not removed, making the report appear like a group report.

What changes do you think we should make in order to solve the problem?

  1. First, it needs to be checked why the previousUpdateID for the AddComment response is sent as a higher value than the OpenReport call’s lastUpdatedID/lastClientUpdateID. Fixing this issue should resolve the problem.
  2. However, even with an accidental call to GetMissingOnyxMessages, the previous updates should not be left in limbo without being updated to Onyx until a new write request is made. The updates in the queue need to be written to Onyx after all the missing updates are obtained with GetMissingOnyxMessages. Currently, this is not handled anywhere. When the next write request gets completed and the persistent requests array is empty, all queuedOnyxMessages get updated. We can see this in the present bug as well: if we send another message, everything updates correctly (the backend also does not send an incorrect previousUpdateID) because the queue is unpaused. After processing this request, when the persisted requests are empty, the queuedOnyxUpdates (which include the previous OpenReport and AddComment responses’ onyxData, successData, etc.) are flushed. To achieve this, after fetching the missing messages, we should flush the queue finally by changing this: https://github.com/Expensify/App/blob/78e484f41e5fb5fa3f8827d2b4aea0ba55b581e4/src/libs/actions/OnyxUpdateManager/index.ts#L144 to:
DeferredOnyxUpdates.getMissingOnyxUpdatesQueryPromise()?.finally(finalizeUpdatesAndResumeQueue).then(() => QueuedOnyxUpdates.flushQueue());

What alternative solutions did you explore? (Optional)

c3024 avatar Oct 07 '24 16:10 c3024

@parasharrajat, @RachCHopkins Whoops! This issue is 2 days overdue. Let's get this updated quick!

melvin-bot[bot] avatar Oct 10 '24 18:10 melvin-bot[bot]

@parasharrajat do you like any of the proposals here?

RachCHopkins avatar Oct 11 '24 00:10 RachCHopkins

📣 It's been a week! Do we have any satisfactory proposals yet? Do we need to adjust the bounty for this issue? 💸

melvin-bot[bot] avatar Oct 13 '24 16:10 melvin-bot[bot]

@RachCHopkins I won't be available from 16 Oct for a few days, please reassign.

parasharrajat avatar Oct 14 '24 15:10 parasharrajat

I can take over this issue as C+

DylanDylann avatar Oct 14 '24 15:10 DylanDylann

@parasharrajat @RachCHopkins this issue was created 2 weeks ago. Are we close to approving a proposal? If not, what's blocking us from getting this issue assigned? Don't hesitate to create a thread in #expensify-open-source to align faster in real time. Thanks!

melvin-bot[bot] avatar Oct 14 '24 18:10 melvin-bot[bot]

📣 @DylanDylann 🎉 An offer has been automatically sent to your Upwork account for the Contributor role 🎉 Thanks for contributing to the Expensify app!

Offer link Upwork job Please accept the offer and leave a comment on the Github issue letting us know when we can expect a PR to be ready for review 🧑‍💻 Keep in mind: Code of Conduct | Contributing 📖

melvin-bot[bot] avatar Oct 15 '24 02:10 melvin-bot[bot]

Oops. I'm not sure if that matters 😬

RachCHopkins avatar Oct 15 '24 02:10 RachCHopkins

@DylanDylann how do you feel about the proposals here?

RachCHopkins avatar Oct 16 '24 04:10 RachCHopkins

on my list today

DylanDylann avatar Oct 16 '24 04:10 DylanDylann

It will take me a bit of time to dive deep into this issue because this seems be complicated

DylanDylann avatar Oct 16 '24 04:10 DylanDylann

First, it needs to be checked why the previousUpdateID for the AddComment response is sent as a higher value than the OpenReport call’s lastUpdatedID/lastClientUpdateID. Fixing this issue should resolve the problem.

@c3024 Could you help to detail this point?

DylanDylann avatar Oct 18 '24 10:10 DylanDylann

@DylanDylann

Sure!

https://github.com/user-attachments/assets/637e66ac-85b8-4a36-b6c3-f8fc690d061f

  1. For all write requests, the backend sends a previousUpdateID and a lastUpdateID. In the above video, the lastUpdateID sent back in the OpenReport response is 2468230213. This means the backend considers this ID to be the last time the client device was updated.
  2. Then, when we made an AddComment request, the server’s response returned a previousUpdateID of 2468230219. This means the backend is informing the client that the freshest update it sent previously to all devices is 2468230219. This is larger than the lastUpdateID (2468230213) saved to the device. The backend is suggesting to the client that there are updates between the OpenReport response (2468230213) and the AddComment response (2468230219). However, this is incorrect because it is impossible for there to be any updates in between, as this is the only client making changes to this account. The backend is sending an incorrect previousUpdateID of 2468230219 when it should be sending the lastUpdateID from the OpenReport response, which is 2468230213.
  3. Due to this incorrect previousUpdateID (which is larger than the lastUpdateID), the client thinks it is out of date and pauses applying the AddComment response to Onyx, making a GetOnyxMessages call to retrieve the missing updates. This call returns only the updates between 2468230213 and 2468230219, as can be seen.
  4. The lastUpdateID of a write request response should match the previousUpdateID of the next write request if no other updates have been made by another client to the same report, account, etc.

https://github.com/user-attachments/assets/36aa8a34-43f8-4351-9be5-9c3476b29250

  1. In the above video, I added two more comments. The responses for these AddComment requests have the correct ids. The lastUpdateID of the first comment matches the previousUpdateID of the next comment, so no GetOnyxMessages call is made because the client understands that the chain of updates is intact and nothing is missing.

There is a fix required on the backend for the first AddComment response after the OpenReport response. However, there is also a generic problem in the frontend codebase, as mentioned in the RCA and the second point of my suggested solution. The issue is that the last write response (in this case, AddComment, along with the updates waiting in queuedOnyxUpdates) which triggered the GetMissingOnyxMessages call, is not immediately written after the missing updates are fetched though the SequentialQueue is paused after fetching these missed updates. This happens because there is no code to flush the queuedUpdates unless another response is received from the backend, as outlined in the second point of my solution.

When the next write request gets completed and the persistent requests array is empty, all queuedOnyxMessages get updated. We can see this in the present bug as well: if we send another message, everything updates correctly (the backend also does not send an incorrect previousUpdateID) because the queue is unpaused. After processing this request, when the persisted requests are empty, the queuedOnyxUpdates (which include the previous OpenReport and AddComment responses’ onyxData, successData, etc.) are flushed.

Feel free to ask if there is still something unclear. As you mentioned, this is a fairly complex issue, and I may have missed explaining some parts fully in an effort to keep the comments concise.

c3024 avatar Oct 18 '24 11:10 c3024

@c3024 Thanks for a deep explanation

DylanDylann avatar Oct 21 '24 11:10 DylanDylann

Updated proposal

  • Update the RCA and solution

  • I suggested the logic here but in the past, we thought it was unnecessary and moved the logic to the flush function.

nkdengineer avatar Oct 22 '24 05:10 nkdengineer

@DylanDylann My solution here can fix both issues. @nkdengineer your updated solution is the same as mine.

mkzie2 avatar Oct 22 '24 05:10 mkzie2

@nkdengineer

For the reason why GetMissingOnyxMessages API is called I think maybe it's expected from BE.

Why do you think it is expected?

DylanDylann avatar Oct 22 '24 09:10 DylanDylann

Hi @mkzie2, Thanks for your contribution, your solution and @nkdengineer's solution have the same idea. But the @nkdengineer proposed it first in https://github.com/Expensify/App/issues/46393#issuecomment-2255598546

DylanDylann avatar Oct 22 '24 09:10 DylanDylann

Why do you think it is expected?

I'm not sure about the logic of it, that's my guess.

nkdengineer avatar Oct 22 '24 09:10 nkdengineer

Thanks everyone for your inputs

I agree with @c3024 about your RCA

  1. previousUpdateID on the AddComment API is weird (more detail here). But I am not sure about the BE logic. Let's wait for an internal engineer to verify that

  2. We don't have the logic to flush OnyxUpdateQueue when it is unpaused. With this problem, I lean toward @nkdengineer's proposal.

🎀 👀 🎀 C+ reviewed

DylanDylann avatar Oct 22 '24 09:10 DylanDylann