Debouncing for a better performance

We recently had a performance escalation that required quite a bit of investigation to figure out the underlying cause. We observed unacceptable load times for a user trying to view their daily schedule, especailly if they had 30 items or more.

Context

We are working on a store subscription mechanism where the view receives an update whenever a relevant change occurs in the store. The views are written using swiftUI, which helps us write the views as a function of the updated content in the store.

Initial investigation

Mocking appropriate data and running through the workflow yielded an interesting insight that load times were getting slower and slower as the user would tap across multilpe dates with large number of items on the schedule.

The idea was then to measure the times it took to tap back and forth between a couple of dates, waiting for the visual comfirmation of load being completed before switching to the previous date. This back and forth was done 5 times (for a total of 10 daily schedule loads, with each date being loaded having 30 items on schedule).

We measured times using a stop watch and measured not just the time it took for the initial load, but also the times it took for subsequent loads. Between multiple runs of the workflow, we landed at an average of 57 seconds.

In addition we observed that subsequent loads took longer than prior loads, additionally if we waited for a while, then the initial load times would return for subsequent loads.

Identifying potential bottlenecks

We are working through a new storage mechanism. We had the following ideas:

• Writing to the store was slow
• Reading from the new store was slow
• Combine publisher that updates state for swiftUI based view was slow

Understanding the bottleneck

To begin this we had to identify some functions that time profiler instrument in xcode instruments idenitifed as being present a lot during the duration of the slow down.

There were a couple of functions that showed up a lot in the time profiler, leading us to believe that we were performing slow operations too many times.

We applied the following block to areas in code to detect the following in addition to the worflow time:

• total time spent during the workflow on writing data to the store
• total time spent during the workflow on reading data from the store
• total time spent during the workflow on figuring out which queries we needed to make

Realization

Off the 57 seconds on the workflow, 2.5 seconds were spent on writing content to the store. Rest of it was spent mostly on reading data from the store (about 52 seconds).

While individual reads were fast, we were performing the same read operation too many times. All these read operations were put on the same DispatchQueue, which slowed down the loads for subsequent read operations. This also explained why load times became better after the queue of async operations on the DispatchQueue were completed.

When we received data from the server, we were inserting multiple items corresponding to the items that show up on users schedule, Each of these was causing the query result to be recomputed.

Debouncing

Instead of recomputing the result with every relevant change that was performed on the store, we waited for no relevant changes to occur for 50ms before asking the store to fulfill the query.

After making this change however we still had the following numbers: worflow time = 56 seconds , time spent writing = 2.5 seconds, time spent reading = 3.4 seconds.

This was pretty disheartening because even after reducing the time spent reading, the workflow time had no real impact.

Upon looking at the profiler instrument again, we observed that another function that computed which queries to perform on the store showed up in a lot of snapshots.

Everytime reuslt for a query was provided, the result of the query was being used to determine any additional queries that need to be defined in order for the view state to be computed. Based on the success with reduced read times that we had with the debounce operation, we deciced to debounce this operation as well, to only recompute new queries when no new query results werew available for 50ms.

This led to a soignificant improvement in performance, with the net workflow times dropping to a now acceptable 14.6 seconds.

Causes of worry during the implemenation

We were worried that 50ms debounces would add up and will lead to eventual slow down, but by reducing the number of async operations that got queued up on different dispatch queues, we were able to improve the overall workflow time significantly.