Krótka historia o optymalizacji

11/8/2020

Jakiś czas temu na Twitterze zamieściłem zrzut ekranu pokazujący flame-chart z narzędzia Profiler. Pracowałem wtedy nad poprawą wydajności aplikacji, którą rozwijamy w Egnyte. Pewna funkcjonalność, dla dużej ilości danych, zajmowała strasznie dużo czasu - 3,5 minuty! Przez ten czas w aplikacji pokazywany był "kręciołek", a użytkownik nie wiedział, czy coś się dzieje, czy może coś się zawiesiło. Po kilku dniach pracy z Profilerem udało mi się zaimplementować poprawki, które zredukowały czas potrzebny do obliczeń z 3,5 minuty do 35 sekund. W tym wpisie chciałbym opisać jak do tego doszedłem.

Opis funkcjonalności

Zacznijmy od opisu funkcjonalności, która krótko mówiąc kulała pod względem wydajności. Jednym z głównych widoków w naszej apce jest tzw. "Sensitive Content". Pokazujemy tu listę folderów z plikami, które zawierają wrażliwe dane. To mogą być numery kart kredytowych, dane medyczne, personalne i nie tylko. Dane te mogą podchodzić pod jedną z kilkunastu wbudowanych polityk np. HIPA, GDPR, ale również dajemy możliwość użytkownikom zdefiniowana własnej polityki np. w oparciu o utworzony wcześniej słownik. Początkowo widok "Sensitive Content" pokazywał tylko płaską listę folderów. W zeszłym roku nasz Product Owner wraz z zespołem UX doszli do wniosku, że praca z płaską listą folderów może być nieefektywna. Zamiast tego dużo lepszym, i w zasadzie bardziej naturalnym sposobem reprezentacji danych, będzie drzewko folderów.

Algorytm budowania drzewa

Podejść do drzewek było już u nas w projekcie kilka. Głównie opierały się one na własności folderu jakim było unikalne folderId. Niestety, w przypadku "Sensitive Content" nie mogliśmy tego użyć, ponieważ nie wszystkie foldery mogły zawierać wrażliwe dane, a tylko dla takich folderów dostawaliśmy folderId.

/Shared/A/B/

W tym wypadku mamy 3 foldery (Shared, A, B), z czego tylko dla B dostajemy folderId

Takich lokacji z SC (Sensitive Content) może być multum. Problem wydajności pojawiał się już przy 250 tysiącach lokacji. A że nie jest to wyjątek utwierdził nas klient, u którego znaleźliśmy prawie milion folderów. To właśnie dla 1M elementów listy, czas budowania drzewka wynosił 3,5 minuty. Dlatego też, moje zadanie polegało na tym, że drzewko dla 1M elementów ma się budować w mniej niż 60s.

Wracając do algorytmu. Prosty - jak budowa cepa - tak by się wydawało :)

Weź całą ścieżkę i podziel ją na fragmenty wg. separatora np. /
Każdy folder wsadź do dwóch struktur: "drzewiastej" i "płaskiej"
Jeśli folder nie ma folderId traktuj go jako meta-folder

Dla uproszczenia pomijam kwestię tego, że wspieramy różne źródła danych i te separatory mogą się mocno różnić :) Co więcej, jak się później okazało, niektóre źródła danych mogą mieć dwa foldery o tej samej nazwie, na tym samym poziomie zagnieżdżenia 😱. I jak je rozróżnić? Pominę też kwestię tego, że wynikowe drzewo mieliśmy przedstawić w formie "sparse-tree". W skrócie - chodzi o to, że jeśli folder zawiera tylko jeden sub-folder, to ścieżka rodzica powinna być zwinięta/scalona.

Lista:

/Shared/A/B/C
/Shared/A/B/D

-->
Drzewo:

/Shared/A/B
    /C
    /D

Pierwsza, a w zasadzie druga implementacja

Jak już wspomniałem wcześniej, nie było to pierwsze drzewo, jakie mieliśmy wyświetlić w aplikacji. W zupełnie innym widoku, też mieliśmy zrobić sparse-tree i nie chcieliśmy mieć kilku różnych implementacji. Dlatego napisaliśmy prosty moduł do budowania i zarządzania drzewkiem. Oparty został o dwa małe komponenty:

funkcję buildTree, która przyjmowała płaską tablicę węzłów i miejsce (ścieżkę w drzewie) od którego miała te węzły wstawiać
"plasterek" (slice) z redux-toolkit, który zarządzał strukturą drzewa (rozwijanie, zwijanie węzłów itp.)

Całe drzewo, a w zasadzie te dwie struktury "drzewiasta" i "płaska", trzymane były w reduxie w następujący sposób:

{
    tree: {
        path: "", // root
        children: {
            "Shared": { // path-part or folder name as a key
                path: "/Shared",
                children: {
                    "A": {
                        path: "/Shared/A",
                        children: {}
                    }
                }
            }
        }
    },

    paths: {
        "/Shared": {
            meta: true,
            ...nodeProps
        }
        "/Shared/A": {
            meta: false,
            folderId: "some-unique-id",
            ...nodeProps
        }
    }
}

Taką strukturę otrzymujemy z pomocniczej funkcji buildTree.

Dzięki zastosowaniu redux-toolkit, a co za tym idzie biblioteki immer, mogliśmy w bardzo prosty sposób wykonywać operacje na drzewie:

const initialTreeState = {
  initialized: false,
  tree: {
    path: "",
    children: {},
  },
  paths: {},
}

export const createTreeSlice = treeName =>
  createSlice({
    name: treeName,
    initialState: initialTreeState,
    reducers: {
      insertTree: ({ tree, paths }, { payload }) => {
        paths = {
          ...paths,
          ...payload.paths,
        }
        const node = getNodeByPath(payload.parentPath || "", tree)
        node.children = payload.tree.children
      },

      toggleNode: ({ tree }, { payload: path }) => {
        const node = getNodeByPath(path, tree)
        node.expanded = !node.expanded
      },
    },
  })

Pomocnicza funkcja getNodeByPath służy do wyszukiwania węzła po ścieżce. Potrafi też wyszukać węzeł w sparse-tree.

Pierwsze podejścia do optymalizacji i pierwsze błędy

No i wszystko pięknie-ładnie, ale przyszedł klient, 1 milion folderów i jebs... Product Owner zakłada Epic w Jirze pt. "Support 1M folders on SC tree view". Szybka burza mózgów i od razu kosz pełen pomysłów:

a może by tak budować drzewo w locie, jak parsujemy JSONa?
a może by tak budować drzewo w web-workerze, przynajmniej nie zablokujemy głównego wątku na 3,5 minuty?
a może by tak, pizgnąć to wszystko i wyjechać w Bieszczady? ⛰ 🐑

A może by tak...

Pierwszy błąd - nikt nawet nie odpalił Profilera, żeby zobaczyć co zajmuje tyle czasu. Każdy założył, że obecna implementacja drzewka wymiata i lepiej być nie może. Sam Profiler na pierwszy rzut oka nie jest prostym narzędziem i może to było powodem tego, że rzuciliśmy się wtedy na tego typu pomysły jak budowanie drzewa "w locie" czy przeniesienie tego do web-workera. Warto też podkreślić, że sam Epic w Jirze powstał już jakiś czas temu, a do samej implementacji usiadłem w połowie października.

Pewnie zastanawiacie się - ale jak to w locie? Przecież jak idzie request to dopiero jak przyjdzie odpowiedź to przeglądarka parsuje JSONa i daje odpowiedź. Tak, ale...w tym przypadku nasi backendowcy też musieli podziałać trochę w kwestii optymalizacji i zamiast zwracać pełne dane to zaczęli tę naszą listę SC zwracać na zasadzie stream'u. Dzięki temu mogliśmy np. wykorzystać bibliotekę oboe.js to parsowania JSONa w locie.

Oczywiście spróbowałem tego podejścia, no bo w końcu ktoś to wpisał do zadania w Jirze, trzeba było sprawdzić co nie? 😜 Fajnie, JSON parsował się "w locie", ale stream zamiast 10s trwał 30s, a jeszcze nie zacząłem nawet budować drzewa. Dlatego odpuściłem i postanowiłem poszukać gdzie indziej.

Web-worker

Podejście z web-workerem też przetestowałem. Ale tu napotkałem zupełnie inny problem. Ok - mogę sobie pobrać 1M elementów i zbudować na tej podstawie drzewo, ale muszę je później przesłać z wątku web-workera do wątku głównego. Struktura drzewa jest dość obszerna, razem z danymi, które zapisywaliśmy w tej płaskiej strukturze paths. Jeśli chcemy przesłać tak duże dane z jednego wątku do drugiego, przeglądarka musi te dane zserializować, przesłać, a następnie ponownie sparsować. To też powodowało "zamrożenie" przeglądarki na czas przesyłania z jednego miejsca pamięci do drugiego. Oczywiście są sposoby na przesłanie "bezpośrednie" (bez kopiowania) poprzez tzw. Transferable Objects np. ArrayBuffer, ale uznałem, że na chwilę obecną to może być gra nie warta świeczki i postanowiłem sprawdzić, czy faktycznie ta nasza implementacja drzewka była tak zajebista jak myśleliśmy 😜

Profiler podejście pierwsze

Usiadłem przed ekranem komputera, odpaliłem dev-toolsy i wcisnąłem przycisk "record" w Profilerze. Po chwili dostałem taki kolorowy wykresik, który przypomniał mi czasy defregmentatora dysków z Windowsa 98 🤣

Pierwsze co rzuciło mi się w oczy to ten fioletowy kolor, który zanurkował bardzo, bardzo głęboko. Po bliższym spojrzeniu okazało się, że bardzo dużo tych fioletowych elementów to sprawka immer.js. Szybki rzut oka w dokumentację i boom! strzał w dziesiątkę. Okazuje się, że przy "wkładaniu" dużej ilości danych poprzez immer możemy przyspieszyć ten proces poprzez Object.freeze tutaj więcej info. Zabieg ten pozwolił mi na zejście z 12,54s na 11,24s dla 54K elementów. Dla 1M skok był oczywiście proporcjonalnie większy. No ale to nadal nie było to...

Od profilera, do źródeł

Wiedzieliście, że jak klikniecie na dany blok w Profilerze, a następnie przeniesiecie się do pliku, to dostaniecie czasy dla poszczególnych bloków kodu? Nie!? 😎 To teraz już wiecie ;)

To co się rzuca w oczy to 229ms dla zbudowania prostego ciągu znaków 🤯 jakim jest aktualna ścieżka. Okazało się, że to zwykłe niedopatrzenie można było zastąpić krótszym kawałkiem kodu, który koniec końców zajmuje 1.7ms.

Pomyślicie - (ironicznie) wow... 227ms... "brawo Ty" 👏. Czym jest 227ms? Jeśli spojrzymy na to jako pojedynczą wartość - to fakt...mikro-optymalizacja. Ale pamiętajcie, że celem było obsłużenie 1M elementów, a operacja sklejania ścieżki dotyczyła każdego sub-folderu.

Mój spread operator AKA Object.assign taki piękny

Jak zrobić płytką kopię obiektu, bądź rozszerzyć inny obiekt - nic prostszego - spread operator .... Jeśli musicie wspierać przeglądarki takie jak IE11, to pewnie korzystacie z babel.js - tak jak my...no i taki spread operator, koniec końców jest tłumaczony na Object.assign (w wielkim uproszczeniu).

Object.assign jest stosunkowo wolny i przy większej skali może sprawiać problem. W tym przypadku postawiłem na zwykłe kopiowanie per klucz. Dzięki temu prostemu zabiegowi zbiłem 154ms do 44ms. I znowu, dla pojedynczych elementów to nie ma absolutnie żadnego znaczenia, ale kiedy iterujemy po dużym zbiorze danych takie optymalizacje mogą zdziałać cuda.

Agregacja wartości

Po "podkręceniu" immera i wyrzuceniu kliku Object.assign, bądź przepisaniu ich na prostą pętlę, skończyły mi się pomysły na "proste" optymalizacje. Trzeba było podkręcić sam sposób budowania drzewa.

Poprzednia implementacja, dzieliła sobie SC lokacje wg. źródła i dla każdego z nich budowała pod-drzewo. Dla każdego pod-drzewa liczone były zagregowane wartości (np. jeśli folder sam w sobie zawierał 10 SC, ale miał dodatkowo 50 sub-folderów, chcieliśmy pokazać zsumowane wartości). Dla każdego takiego pod-drzewa, wykonywane były sumowania, a następnie węzeł źródła był aktualizowany wg. zsumowanych wartości dla wszystkich folderów.

Każda taka operacja wrzucała coś do stanu w redux'ie. Pomyślałem - a na co to komu? A komu to potrzebne? Przecież nie pokazujemy drzewa dopóki wszystko nie jest policzone i zaktualizowane. Dlatego, zmieniłem kod tak, aby najpierw zbudować w pamięci całe drzewo wraz z policzonymi zagregowanymi wartościami, a następnie za pomocą jednej operacji, wsadzić zbudowane drzewo do reduxa.

Co więcej - w wymaganiach drzewka, było napisane, że pewne węzły miały być domyślnie rozwinięte np. pierwszy poziom + potencjalnie wcześniej zaznaczony element na liście (z listy do drzewka można przejść za pomocą prostego przycisku). Wcześniej operacje rozwijania były wyzwalane za pomocą akcji toggleNode. To też zmieniłem - zamiast odpalać reduxową akcję, po prostu zmieniam wartość expanded na true bezpośrednio w obiekcie węzła.

Można zapytać - co Ci to dało drogi Panie?

Dla 54K elementów zjechałem z czasu 12,25s na 2,4s 🚀

Łogień w szopie :) Product Owner cały w skowronkach.

Wow

Testy dla 1M

Poprosiłem backendowców, żeby przygotowali mi środowisko do testów dla 1M elementów. Chciałem sprawdzić czy moje optymalizacje dla 54K znajdą uzasadnienie. No i uśmiech nie uciekł z mej twarzy :)

Przed optymalizacją czas budowania drzewa wynosił ~3,5 minuty. Po zaaplikowaniu wyżej wymienionych zmian udało się zjechać do 59s.

Mniej więcej ~70% oszczędności. W sumie można by powiedzieć - job done - miało się budować w mniej niż 60s... 59 to mniej niż 60 😅 Jest git...

Trochę byłem już zmęczony tym grzebaniem w de-facto w nie swoim kodzie...ale kumpel z zespołu słusznie stwierdził:

No fajnie, fajnie, ale dla mnie nadal to jest wolno.

Dodał też potem, że nic mi nie ujmuje i wg. niego wykonałem kawał dobrej roboty...ale trudno było się z nim nie zgodzić. Od momentu kliknięcia w element nawigacji, do czasu wyświetlenia widoku, użytkownik musiał poczekać łącznie 90s:

25s pobieranie danych (streaming)
6s przeglądarka parsuje JSONa
59s budowanie drzewa

Jako użytkownik, gdybym przez 90s widział tylko spinner ("kręciołek") to by mnie szlag trafił :) Nie chcę myśleć, co czuli nasi użytkownicy jak musieli czekać 3,5 minuty...pewnie żaden nie wytrzymał 😅

...no...ale wracając...kumpel mówi: "wolno"...no to ja od razu: "co!? wolno!? ja Ci pokażę!" 🤣

Generowanie ID

Znowu zanurkowałem w Profiler. Dla meta-folderów generowny był folderId. Było to spowodowane tym, że inne miejsce w kodzie tego id potrzebowało (mniejsza o to). Koniec końców to generowane id nic nie znaczyło (nigdy nie było wysyłane do backendu). Ktoś jednak wymyślił, że to meta-folder-id ma być haszem ze ścieżki...

export const createUniqueIdForLocation = path => btoa(encodeURIComponent(path))

Funkcja btoa koduje ciąg znaków jako base64. Sama w sobie trwa średnio 0,25ms...czyli ułamek milisekund. Ale gdy mocniej się zastanowimy - a na co komu ten hasz? a na co komu to potrzebne?

Ale po co?

No właśnie! Jeśli meta-folder-id to tylko base64 ze ścieżki, która de facto zawierała też w sobie id źródła, więc była unikatowa względem całej listy, to po co to w ogóle ten cały hash?

-            id: createUniqueIdForLocation(path),
+            id: path,
             name: getLocationName(path),

Ten jeden diff sprawił, że dla 1M elementów zszedłem z 59s na 35s, co dało ~40% zysku 🤯

Czyli teraz klient nie czekał już 90s a 66s - łącznie z pobieraniem i parsowaniem danych! Biorąc pod uwagę, że wymagania mówiły o budowaniu drzewka w czasie mniejszym niż 60s, to chyba Product Owner oraz klienci powinni być zadowoleni 😅

Dalsze kroki

Oczywiście nie spoczywamy na laurach. Blokowanie użytkownika na 60s nadal jest kiepskim pomysłem, dlatego dalej myślimy o ulepszeniu implementacji. Być może wyrzucimy to w końcu do web-workera. Kto wie? Może uda mi się dzięki temu zebrać materiał na następnego posta 😉.

Podsumowanie

Lekcja pierwsza - zamiast gdybać i sypać pomysłami z kapelusza o web-workerach, lepiej odpalić Profiler.

Lekcja druga - jeśli operujesz w dużej skali, iterujesz po dużym zbiorze danych, to optymalizacje na poziomie ms dla jednej iteracji potrafią czynić cuda 🚀

Lekcja trzecia - do reduxa wrzucaj dopiero wtedy, kiedy jesteś gotów 💪

Lekcja czwarta - jeśli nie ma potrzeby, to nie komplikuj sytuacji 😉 (patrz ID & btoa).

Mam nadzieję, że dzięki tej historii sięgniecie wcześniej do Profilera i uda się Wam poprawić wydajność nie jednej aplikacji.