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

[Performance] User unable to navigate to chat in search results (slow API call blocks the whole app?) #46593

Open
1 of 6 tasks
hannojg opened this issue Jul 31, 2024 · 26 comments
Assignees
Labels
Engineering Monthly KSv2 Reviewing Has a PR in review

Comments

@hannojg
Copy link
Contributor

hannojg commented Jul 31, 2024

If you haven’t already, check out our contributing guidelines for onboarding and email contributors@expensify.com to request to join our Slack channel!


What performance issue do we need to solve?

The customer was opening NewDot and doing a search. The account is quite big. When running search for the first time in the app the SearchForReports took 110 seconds.

During that time the user clicked on a search result, but nothing happens. The user is only brought to the chat once the search API call finishes.

See this recording:

search_taking_forever.mov

What is the impact of this on end-users?

  • Very high TTI to open search page
  • Very long time for search results to come in

List any benchmarks that show the severity of the issue

The customer shared a profile trace with us:

Firefox 2024-07-25 10.42 profile.json.gz

(note: the trace also contains other test cases as well)

Additionally we have a HAR recording of the network requests that took that long. I hope that helps in identifying the query in the backend log system:

www.expensify.com_07-31-2024-16-53-27.har.zip

Proposed solution (if any)

None yet, I will go through the profile and see what can be optimised, what exactly caused those lags.

List any benchmarks after implementing the changes to show impacts of the proposed solution (if any)

not available yet

Platforms:

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

  • Android: Native
  • Android: mWeb Chrome
  • iOS: Native
  • iOS: mWeb Safari
  • MacOS: Chrome / Safari
  • MacOS: Desktop

Version Number: v9.0.11-5
Reproducible in staging?: not tested
Reproducible in production?: yes
Email or phone of affected tester (no customers): customer
Logs: See performance file
Notes/Photos/Videos: See attached video
Expensify/Expensify Issue URL: n/a
Issue reported by: @hannojg
Slack conversation: https://expensify.slack.com/archives/C05LX9D6E07/p1721919928992729

View all open jobs on Upwork

Copy link

melvin-bot bot commented Jul 31, 2024

Auto-assigning issues to engineers is no longer supported. If you think this issue should receive engineering attention, please raise it in #whatsnext.

@hannojg
Copy link
Contributor Author

hannojg commented Jul 31, 2024

cc @sakluger (feel free to assign me as I (or someone from my team) will work on this ticket!)

@hannojg hannojg changed the title [Performance] SearchForReports took 110602ms (~2min) to complete seemingly blocking the whole app [Performance] SearchForReports took 110602ms (~2min) to complete, seemingly blocking the whole app Jul 31, 2024
@marcaaron
Copy link
Contributor

Just for context, on the backend side, it is a known issue that SearchForReports can sometimes be extremely slow.

@marcaaron marcaaron self-assigned this Aug 2, 2024
@melvin-bot melvin-bot bot added the Overdue label Aug 5, 2024
@sakluger
Copy link
Contributor

sakluger commented Aug 5, 2024

No update

@melvin-bot melvin-bot bot added Overdue and removed Overdue labels Aug 5, 2024
@sakluger
Copy link
Contributor

sakluger commented Aug 8, 2024

No update

@melvin-bot melvin-bot bot added Overdue and removed Overdue labels Aug 8, 2024
@sakluger
Copy link
Contributor

No update

@melvin-bot melvin-bot bot removed the Overdue label Aug 12, 2024
@hannojg
Copy link
Contributor Author

hannojg commented Aug 14, 2024

I just opened a PR hat shows a PoC for using web workers for running the search, which will unblock the main thread:

I am now seeking approval on this new technical design here.

(Note: I am OOO for the rest of the week and will continue next week Monday 19.08)

@sakluger sakluger added Weekly KSv2 and removed Daily KSv2 labels Aug 15, 2024
@sakluger
Copy link
Contributor

Moving to weekly for now since Hanno is out until Monday.

@hannojg
Copy link
Contributor Author

hannojg commented Aug 19, 2024

@kirillzyusko do you have time to look into that in parallel? Should be able to just slow down the SearchForReports requests using a tool like Proxyman to try to reproduce this!

@kirillzyusko
Copy link
Contributor

@hannojg sure, I'll look into this 👀

@sakluger
Copy link
Contributor

@kirillzyusko thanks for helping! FYI I'll be OOO for the next week - hopefully, there will be some interesting new learnings when I return on 8/30.

@kirillzyusko
Copy link
Contributor

@marcaaron may I kindly ask you to verify a duration of this request on BE:

POST https://www.expensify.com/api/SearchForReports? HTTP/1.1
Host: www.expensify.com
User-Agent: Mozilla/5.0 (Windows NT 10.0; Win64; x64; rv:128.0) Gecko/20100101 Firefox/128.0
Accept: */*
Accept-Language: en-US,en;q=0.5
Accept-Encoding: gzip, deflate, br, zstd
Referer: https://new.expensify.com/
Content-Type: multipart/form-data; boundary=---------------------------224365322038742656772464040988
Content-Length: 2128
Origin: https://new.expensify.com
Connection: keep-alive
Sec-Fetch-Dest: empty
Sec-Fetch-Mode: cors
Sec-Fetch-Site: same-site
Priority: u=4
Pragma: no-cache
Cache-Control: no-cache
TE: trailers

-----------------------------224365322038742656772464040988
Content-Disposition: form-data; name="searchInput"

sasha@expensify.com
-----------------------------224365322038742656772464040988
Content-Disposition: form-data; name="canCancel"

true
-----------------------------224365322038742656772464040988
Content-Disposition: form-data; name="apiRequestType"

read
-----------------------------224365322038742656772464040988
Content-Disposition: form-data; name="authToken"

REDACTED
-----------------------------224365322038742656772464040988
Content-Disposition: form-data; name="referer"

ecash
-----------------------------224365322038742656772464040988
Content-Disposition: form-data; name="platform"

web
-----------------------------224365322038742656772464040988
Content-Disposition: form-data; name="api_setCookie"

false
-----------------------------224365322038742656772464040988
Content-Disposition: form-data; name="email"

expensify@nutanix.com
-----------------------------224365322038742656772464040988
Content-Disposition: form-data; name="isFromDevEnv"

false
-----------------------------224365322038742656772464040988
Content-Disposition: form-data; name="appversion"

9.0.11-5
-----------------------------224365322038742656772464040988
Content-Disposition: form-data; name="clientUpdateID"

730608865
-----------------------------224365322038742656772464040988--

Timings of request are:

image

As I can see the BE couldn't complete the request and returned:

{
  "jsonCode": 555,
  "message": "555 Timeout peeking command",
  "onyxData": [],
  "requestID": "8a8df5b19956171a-SJC"
}

But if you can double check that in your logs that would be a dope ❤️

@melvin-bot melvin-bot bot removed the Overdue label Aug 30, 2024
@sakluger
Copy link
Contributor

Adding @kirillzyusko as an assignee on the issue.

@marcaaron
Copy link
Contributor

ah sorry, it's just outside the window of when we stop storing the logs.

@sakluger
Copy link
Contributor

sakluger commented Sep 6, 2024

We're working on a PR that improves search speed (#48652). Hopefully that helps here too!

@sakluger
Copy link
Contributor

No major updates, PR is still in progress.

@melvin-bot melvin-bot bot added the Overdue label Sep 23, 2024
@marcaaron
Copy link
Contributor

What's the latest on this one?

@melvin-bot melvin-bot bot removed the Overdue label Sep 25, 2024
@kirillzyusko
Copy link
Contributor

@marcaaron I think @hannojg is working hard and pushing the PR forward. This PR is in review stage now 👀

@hannojg
Copy link
Contributor Author

hannojg commented Oct 2, 2024

Hey, i have a little update on this one. It seems we identified one of the performance issues that were occurring for the customer.

Here is a profile trace that captures the lag/hang:

Trace-20241001T081231.json.zip

It specifically happens in OptionListContextProvider around these lines:

Screenshot 2024-10-02 at 09 03 25

Object.keys(personalDetails).forEach((accountID) => {
const prevPersonalDetail = prevPersonalDetails?.[accountID];
const personalDetail = personalDetails?.[accountID];
if (isEqualPersonalDetail(prevPersonalDetail, personalDetail)) {
return;
}
Object.values(reports ?? {})
.filter((report) => !!Object.keys(report?.participants ?? {}).includes(accountID) || (ReportUtils.isSelfDM(report) && report?.ownerAccountID === Number(accountID)))
.forEach((report) => {
if (!report) {
return;
}
const newReportOption = OptionsListUtils.createOptionFromReport(report, personalDetails);
const replaceIndex = options.reports.findIndex((option) => option.reportID === report.reportID);
newReportOptions.push({

We will work on solutions to improve this! Its either:
a) we improve how this operates and make it more efficient
b) with our other PR we are implementing a suffix tree structure for very fast and efficient search. We might replace parts of the Context with that suffix tree, so this code will be restructured anyway

So the current PR won't fix that, but we are on the way to get this one here fixed as well; will keep you updated!

@marcaaron
Copy link
Contributor

Sorry have been OOO - but that all sounds really promising, thanks!

@marcaaron marcaaron added the Reviewing Has a PR in review label Oct 11, 2024
@melvin-bot melvin-bot bot added Monthly KSv2 and removed Weekly KSv2 labels Nov 4, 2024
Copy link

melvin-bot bot commented Nov 4, 2024

This issue has not been updated in over 15 days. @sakluger, @hannojg, @kirillzyusko, @marcaaron eroding to Monthly issue.

P.S. Is everyone reading this sure this is really a near-term priority? Be brave: if you disagree, go ahead and close it out. If someone disagrees, they'll reopen it, and if they don't: one less thing to do!

@hannojg
Copy link
Contributor Author

hannojg commented Nov 5, 2024

I think this is still important, we are currently trying to allocate this task to someone in the team working on this soon! Monthly seems fine though

@marcaaron
Copy link
Contributor

Are we still actively working on this one?

A backend issue that should optimise the SearchForReports query

I don't think anyone is actively looking into this. But I got curious about whether the performance is still bad and checked out charts for this one and it's mostly not too bad, but there is still one user who has crazy bad times for some unknown reason.

I'm also trying to tell the difference between this issue and this one here: #46590

Can we consolidate maybe?

@hannojg
Copy link
Contributor Author

hannojg commented Nov 26, 2024

Hm, they are a bit different. This one is about that while actively searching the performance is bad, the other one is about opening the search page for a fresh session for the first time being quite slow.

@marcaaron
Copy link
Contributor

Ok thanks, I think I will remove the stuff about this being "two parts" and related to the server then - just to give some clearer focus to the issue.

@marcaaron marcaaron changed the title [Performance] SearchForReports took 110602ms (~2min) to complete, seemingly blocking the whole app [Performance] User unable to navigate to chat in search results (slow API call blocks the whole app?) Nov 26, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
Engineering Monthly KSv2 Reviewing Has a PR in review
Projects
None yet
Development

No branches or pull requests

4 participants