Item status refresh after editing can get confusingly slow

Bug #1821094 reported by Jane Sandberg
30
This bug affects 5 people
Affects Status Importance Assigned to Milestone
Evergreen
Fix Released
Medium
Unassigned
3.11
Fix Released
Undecided
Unassigned
3.12
Fix Released
Undecided
Unassigned

Bug Description

Steps to recreate:
* Scan ~100 barcodes into item status
* Edit a few of them. Save & Exit.
* Note that you get the "Saved" icon immediately, and the "Item(s) saved" toast in the bottom right corner too. However, it's not until a few seconds later that the grid refreshes with the most up-to-date data, which seems like it could cause some confusion.

Maybe the refresh could pay attention to the pager, and only refresh the visible rows? Or maybe there could be some visual indicator that the refresh is loading?

Revision history for this message
Beth Willis (willis-a) wrote :

EG 3.2.4

I loaded 122 items to the Item Status screen and edited 5. I did see the new "Saved" icon display immediately upon saving the items and also the "Items saved" indicator in the lower right hand corner of the screen. The edited values, however, did not display for approximately 30 seconds.

Changed in evergreen:
status: New → Confirmed
Revision history for this message
Jane Sandberg (sandbergja) wrote :

Another thing that would help: I intentionally have the itemSvc.fetch calls running sequentially, rather than concurrently so that the rows don't get out of order. If itemSvc.fetch offered a way to fetch a row in place, rather than unshifting, we could run those calls concurrently without the sorting issue.

Revision history for this message
Elaine Hardy (ehardy) wrote :

What version of EG is the new icon available on?

Revision history for this message
Elaine Hardy (ehardy) wrote :

the new save icon

summary: - Item status refresh after editting can get confusingly slow
+ Item status refresh after editing can get confusingly slow
Revision history for this message
Jane Sandberg (sandbergja) wrote :

It's currently just in master, Elaine. It was added during bug squashing week.

Revision history for this message
Elaine Hardy (ehardy) wrote : Re: [Bug 1821094] Re: Item status refresh after editing can get confusingly slow

Thanks!

J. Elaine Hardy, PINES and Collaborative Projects Manager
------------------------------

Georgia Public Library Service

1800 Century Place, Suite 580 | Atlanta, GA 30345

(404) 235-7128 | <email address hidden>

(404) 548-4241 | Cell

<https://www.facebook.com/georgialibraries>
<https://www.twitter.com/georgialibs>

Join our email list <http://georgialibraries.org/subscription> for stories
of Georgia libraries making an impact in our communities.

On Fri, Mar 22, 2019 at 12:50 PM Jane Sandberg <email address hidden>
wrote:

> It's currently just in master, Elaine. It was added during bug
> squashing week.
>
> --
> You received this bug notification because you are subscribed to
> Evergreen.
> Matching subscriptions: <email address hidden>
> https://bugs.launchpad.net/bugs/1821094
>
> Title:
> Item status refresh after editing can get confusingly slow
>
> Status in Evergreen:
> Confirmed
>
> Bug description:
> Steps to recreate:
> * Scan ~100 barcodes into item status
> * Edit a few of them. Save & Exit.
> * Note that you get the "Saved" icon immediately, and the "Item(s)
> saved" toast in the bottom right corner too. However, it's not until a few
> seconds later that the grid refreshes with the most up-to-date data, which
> seems like it could cause some confusion.
>
> Maybe the refresh could pay attention to the pager, and only refresh
> the visible rows? Or maybe there could be some visual indicator that
> the refresh is loading?
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/evergreen/+bug/1821094/+subscriptions
>

Revision history for this message
John Amundson (jamundson) wrote :

I'm seeing confusingly slow refreshes with even smaller item sets on my training server, (even as little as 10 items).

It's very easy to think everything is set and then have the screen "randomly" refresh on you 30 seconds later.

Staff need at least some way of knowing the refresh is going to happen.

We recently upgraded our production servers to 3.2, and the slow refresh was one of the reasons we went with 3.2.4 over 3.2.5.

Changed in evergreen:
assignee: nobody → Jane Sandberg (sandbej)
Revision history for this message
Jane Sandberg (sandbergja) wrote :

I'll take a stab at this. My plan is to:

* add another option to itemSvc.fetch to skip the unshifting, so that these calls can be done concurrently (aka speed up the refresh)
* let the user know if the refresh is taking a while, probably with a toast message in the bottom right corner
* wait on the "Item(s) saved" toast until after the refresh, to cut down on some of that confusion

...and see how much that helps.

Revision history for this message
Jane Sandberg (sandbergja) wrote :

Here we go! For me, this branch works up to 10 times faster than the old version did. It fetches the updated rows concurrently, rather than sequentially. Also, it only fetches the updated rows, not the ones that haven't been edited.

Also adds a progress bar if the refresh takes 2 seconds or longer.

Branch name: user/sandbergja/lp1821094_item_status_reload_performance
Link: https://git.evergreen-ils.org/?p=working/Evergreen.git;a=shortlog;h=refs/heads/user/sandbergja/lp1821094_item_status_reload_performance

tags: added: pullrequest
Changed in evergreen:
assignee: Jane Sandberg (sandbej) → nobody
importance: Undecided → Medium
Changed in evergreen:
milestone: none → 3.3.1
tags: added: performance
Changed in evergreen:
milestone: 3.3.1 → 3.3.2
Changed in evergreen:
assignee: nobody → Jason Stephenson (jstephenson)
Changed in evergreen:
assignee: Jason Stephenson (jstephenson) → nobody
Revision history for this message
John Amundson (jamundson) wrote :

Thanks for your work on this, Jane.

The time improvements are great. It is about 5 times faster in my testing.
Pre-patch:
20 items on screen
- edit 1 item: 10 seconds for screen to reload; 2 seconds to come back
- edit 5 items: 10 seconds for screen to reload; 2 seconds to come back
- edit 20 items: 15 seconds for screen to reload; 3 seconds to come back

Post-patch:
20 items on screen:
- edit 1: 2;2
- edit 5: 2;2
- edit 20: 3;2

With the speed increase, I'm actually wondering if the progress bar is even needed. In one of my tests, I had 100 items uploaded to Item Status and I edited 20 of them. The refresh process took more than 2 seconds, so the progress bar appeared. But so many things were happening at once, (i.e. items were edited, screen was refreshing, progress was dropping, list was reloading, etc), the progress bar would sometimes get stuck and lead to odd display issues, (like the attached image). Perhaps increasing the time needed for it to appear would be a good compromise, (i.e 5 or 10 seconds instead of 2).

I also came across a couple other bugs, but I honestly don't know if these occurred before the patch was installed, too, so they might warrant their own launchpad reports:

- If an item has a part, and the item is edited, after the screen refreshes, the part no longer shows in the Parts column. (I did not test or confirm if this is limited to the Parts column)

- Changes made through Edit>Call Numbers are only displayed if the item has already been edited during the session.

Revision history for this message
Jane Sandberg (sandbergja) wrote :

Thanks for your thorough testing, John. The two bugs you mentioned are new with this patch. I'm assigning myself so that I can:

1) Only show the progress bar if a refresh takes 5 seconds or longer
2) Figure out what happened to the missing parts
3) Cause call number changes to trigger a refresh again

tags: removed: pullrequest
Changed in evergreen:
assignee: nobody → Jane Sandberg (sandbej)
Revision history for this message
Jane Sandberg (sandbergja) wrote :

I have force-pushed fixes to all the issues that John discovered in testing. Let me know what you think!

Here are updated testing notes from the updated commit:

To test:
1) Create a file with 500 or more item barcodes.
2) Load your file into Item Status.
3) Select a few rows.
4) Go to Actions > Edit > Items.
5) Make some changes, then Save and Exit.
6) Time how long it takes between clicking
"Save and Exit" and when the grid actually
refreshes.
7) Repeat steps 2-6, but use Actions > Edit
> Call Numbers instead.
8) Apply this commit.
9) Repeat steps 2-7. The time should be much
faster with this commit.
10) Verify that no columns lose their data
when refreshed, especially monograph parts
and in-house use count.
11) Note that there is also a progress bar.

Changed in evergreen:
assignee: Jane Sandberg (sandbej) → nobody
tags: added: pullrequest
Changed in evergreen:
milestone: 3.3.2 → 3.3.3
Revision history for this message
Kyle Huckins (khuckins) wrote :

Thanks for this patch Jane! I have tested this code and consent to signing off on it with my name, Kyle Huckins and my email address, <email address hidden>.

Changed in evergreen:
assignee: nobody → Kyle Huckins (khuckins)
tags: added: signedoff
Changed in evergreen:
assignee: Kyle Huckins (khuckins) → nobody
Galen Charlton (gmc)
tags: added: needsdiscussion
removed: signedoff
Revision history for this message
Galen Charlton (gmc) wrote :

I've tested the patch and it does indeed make updates of the item status grid faster. However, I've observed a tradeoff: when you do the update (or for that matter, when you load the holdings editor with 100+ items, although that's not a concern of this particular patch), it's easy to fire off so many PCRUD requests simultaneously that the pool of open-ils.pcrud backends get saturated.

With the OpenSRF 3.1 request backlog queue, that's not a big deal in the sense that ultimately every request will get handled. However, for as long as open-ils.pcrud is in backlog mode, _all_ PCRUD requests will get queued, which will make other webstaff interlaces slower system-wide.

I think we should look into finding some way to run the PCRUD promises emitted by ItemSvc and friends with a concurrency that is more than one (i.e., chaining them sequentially) but less than infinity so that somebody doing batch work in the Item Status interface is less likely to monopolize PCRUD backends.

A starting point for thinking about how to implement this might be https://glebbahmutov.com/blog/run-n-promises-in-parallel/.

Changed in evergreen:
milestone: 3.3.3 → 3.3.4
Changed in evergreen:
milestone: 3.3.4 → 3.3.5
Changed in evergreen:
milestone: 3.3.5 → 3.4.2
Changed in evergreen:
milestone: 3.4.2 → 3.4.3
tags: removed: needsdiscussion
Revision history for this message
Jane Sandberg (sandbergja) wrote :

Thanks for the helpful feedback, Galen.

I've rebased my branch (user/sandbergja/lp1821094_item_status_reload_performance) and included Kyle's signoff (thanks, Kyle!) I also added a second commit that adds a new factory to the AngularJS client that provides a middle road. It divides an array of, say, pcrud calls into batches. Within a batch, all those calls will run simultaneously. The batches themselves, though, are chained sequentially -- batches wait for the previous batch to complete before starting their own work.

My idea was that it could be a stand-in for $q.all() in simple use cases throughout the AngularJS client, so I've called it egBatchPromises.all().

Switching the item status refresh from $q.all() to egBatchPromises.all() seems to provide a very similar experience to the user. I threw in a few unit tests for certain pieces of the new code, but not all of it. I checked osrfsys.log to verify that OpenSRF is receiving those pcrud calls in batches of 10. All that to say, I've done some testing, but not enough! I'd really appreciate further testing from those more familiar with backend performance testing and writing unit tests for asynchronous code. :-)

Revision history for this message
Jane Sandberg (sandbergja) wrote :

One other note: on the Angular side, RxJS has some nice built-in options for batching concurrent API calls. For example, the RxJS version of $q.all, merge, allows you to pass in a number for how large you want these batches to be [1]. In practice, the Angular client uses merge's cousin mergeMap more often so far, and that also has an option to pass in a batch size argument [2].

Long story short, I'm excited for more Angular and less AngularJS, since it means more RxJS and less $q.

[1] https://github.com/ReactiveX/rxjs/blob/388c4852948660abcff22d7b82ccb0a29c77428c/src/internal/observable/merge.ts#L112
[2] It's called "concurrent" here: https://www.learnrxjs.io/learn-rxjs/operators/transformation/mergemap

Revision history for this message
Elaine Hardy (ehardy) wrote :

While I could not test the back end performance testing, I did double check and make sure editing in item status was still speedy with those changes you may have made with those magical back end issues.

I loaded a file of 516 barcodes in item status on our sandbox. It took abt 3 minutes and 22 seconds to load (a file of 300 barcodes took 1:30 to load, by the way).

I edited 10 items-- it took about 4 seconds to reload and show the saved icon
I edited another 10 call numbers and it too about 3 seconds to return the saved icon on reload.

Changed in evergreen:
milestone: 3.4.3 → 3.4.4
Changed in evergreen:
milestone: 3.4.4 → 3.5.1
Changed in evergreen:
assignee: nobody → Chris Sharp (chrissharp123)
Changed in evergreen:
milestone: 3.5.1 → 3.5.2
Revision history for this message
Terran McCanna (tmccanna) wrote :

Jane, could you please rebase this one?

Changed in evergreen:
milestone: 3.5.2 → 3.6.1
Changed in evergreen:
assignee: Chris Sharp (chrissharp123) → nobody
Changed in evergreen:
milestone: 3.6.1 → 3.6.2
Revision history for this message
Mike Risher (mrisher) wrote :

I tested this out without rebasing it to master. I loaded 100+ barcodes, and then edited 15 at a time. I'm seeing all changes show up simultaneously after a wait of around 1.5 seconds. Looks good on my end. I'll hold off on signing off because I don't have a lot of experience with backend performance testing, as was requested. Also I haven't tested the rebase.

Changed in evergreen:
milestone: 3.6.2 → 3.6.3
Changed in evergreen:
assignee: nobody → Jason Stephenson (jstephenson)
tags: added: needsrepatch
Revision history for this message
Jason Stephenson (jstephenson) wrote :

I tried rebasing this branch on master and chery-picking the commits to release 3.5.3. In both cases, I encountered conflicts that I did not feel comfortable resolving.

I have added the needsrepatch tag as the branch needs to be rebased on master.

Changed in evergreen:
assignee: Jason Stephenson (jstephenson) → nobody
tags: removed: webstaffclient
tags: removed: pullrequest
Changed in evergreen:
milestone: 3.6.3 → 3.6.4
Changed in evergreen:
milestone: 3.6.4 → 3.7.2
tags: added: needsrebase
removed: needsrepatch
no longer affects: evergreen/3.2
no longer affects: evergreen/3.3
no longer affects: evergreen/3.4
no longer affects: evergreen/3.5
Changed in evergreen:
milestone: 3.7.2 → 3.7.3
Changed in evergreen:
milestone: 3.7.3 → none
no longer affects: evergreen/3.6
Revision history for this message
Jane Sandberg (sandbergja) wrote :

Hopefully 3 years is still considered "fashionably late"! Here's a rebased branch: user/sandbergja/lp1821094_item_status_reload_performance-rebased

tags: added: pullrequest
removed: needsrebase
Revision history for this message
Jennifer Weston (jweston) wrote :

Tested this in Cataloging Interest Group meeting.
Results:
Loaded 500 items to Item Status
1st Test - Chose a few (less than 10) items, changed shelving location, refresh time 55 seconds
2nd Test - Chose a different few (less than 10) items, changed call number, refresh time 59 seconds
3rd Test - Chose 100 items, changed shelving location, refresh time 58 seconds

We're not sure if this is slower because it is on a test server.

Revision history for this message
Jennifer Weston (jweston) wrote :

Repeated Test with great results!
Results:
Loaded 500 items to Item Status
1st Test - Chose a few (less than 10) items, changed shelving location, refresh time < 3 seconds
2nd Test - Chose a different few (less than 10) items, changed call number, refresh time < 3 seconds
3rd Test - Chose 100 items, changed shelving location, refresh time 12 seconds

Revision history for this message
Jennifer Weston (jweston) wrote :

I have tested this code and consent to signing off on it with my name, Jennifer Weston, and my email address, <email address hidden>

tags: added: signedoff
Changed in evergreen:
assignee: nobody → Terran McCanna (tmccanna)
Revision history for this message
Terran McCanna (tmccanna) wrote :

Thanks Jane and Jennifer! Committed as far back as rel_3_11

Changed in evergreen:
status: Confirmed → Fix Committed
milestone: none → 3.13-beta
assignee: Terran McCanna (tmccanna) → nobody
Changed in evergreen:
status: Fix Committed → Fix Released
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.