Fix: lakectl local diff slowness #7842

N-o-Z · 2024-06-09T10:12:52Z

Change Description

Background

lakectl local had a bug due to the different way standard FS lists files recursively in comparison with object stores (S3).
A fix was introduced which used the local adapter file walker to be used also for lakectl local, in order to diff between local and remote.
Due to the mentioned change, the local diff performance was greatly impacted.

Bug Fix

Improve local diff performance by creating a new walk functions that simulates the order in which object stores list files.
Relying on the FS walk implementation and modifying the behavior when iterating over directories

Testing Details

Manually testing the scenario of ~500K file diff. Operation time was reduced from 18s to 3s
Existing tests verify correctness was not broken

Breaking Change?

No

Additional info

before:

lakectl local status -l  17.47s user 2.41s system 256% cpu 7.765 total

after:

lakectl local status -l  2.97s user 1.00s system 94% cpu 4.212 total

github-actions · 2024-06-09T10:19:27Z

E2E Test Results - DynamoDB Local - Local Block Adapter

arielshaqed

Not sure about this code. We should find a way to test this very precisely.

pkg/local/diff.go

arielshaqed · 2024-06-09T12:14:32Z

pkg/local/diff.go

+			return nil
+		}
+		if info.IsDir() {
+			// TODO: We don't return dir results for the listing, how will this effect directory markers, and can we even support directory markers?


This is a potentially severe product limitation in lakectl local:

Run Spark directly on lakeFS.

Get that branch into lakectl local.

Commit the branch "unchanged".

Won't we see (many) changes?

This comment is not a new behavior. We didn't support directory markers also before. It came up while I was writing the fix and I thought it was worth mentioning

Can we open an issue for this?

arielshaqed · 2024-06-09T12:20:39Z

pkg/local/diff.go

+		}
+
+		// Sort the queue since adding the suffix might the order might change after adding the suffix
+		sort.Strings(dirQueue)


I don't understand: we sort the queue on every object?! Given that sorting requires at least seeing every object on the queue, this will be slow!

Example

Consider this directory structure:

a0000/a a0001/a a0002/a [...] a9999/a z0000 z0001 z0002 [...] z9999

It contains 10000 directories and 20000 objects in total. I would expect the code to try to sort all 10000 a directories for each of the 10000 z files. Given that sorting is $\Omega(n)$ -- at the very least it needs to go over the entire queue to determine that it is already sorted -- this will perform 100M operations.

This sort of thing can and will happen for many cases. For instance consider a lakeFS repository that contains two tables, each partitioned into 10000 parts. 100M operations guaranteed.

Possible fix

Use at least a priority queue to handle these.

We are sorting all directories that precede a given file (if exists) when walking.
This is necessary since we need to process these directories prior to processing the file itself.
Nevertheless, I have moved the sort to inside the if condition and improved the condition itself

arielshaqed · 2024-06-09T12:23:45Z

pkg/local/diff.go

+		if queueLen > 0 && p > dirQueue[len(dirQueue)-1] {
+			// if file > dirs, handle the dirs first
+			for _, dir := range dirQueue {
+				if err = WalkS3(dir, callbackFunc); err != nil {
+					return err
+				}
+			}
+			dirQueue = []string{} // Empty queue once finished processing dirs
+		}


I do not think that this can be correct. Consider the case

dirQueue[0] < p && p < dirQueue[len(dirQueue)-1]

That is impossible:
for simplicity lets call dirQueue[len(dirQueue)-1] last
and dirQueue[0] first
if p < last ==> p < last - "/" (because otherwise the walk function would have returned p before last
if first < p ==> first - "/" < p
Therefore it mandates that first - "/" < p < last - "/" which means that we should have gotten p from the walk function somewhere between getting first and last and we get a contradiction

I hope the explanation is convincing 😃

I'm retracting my previous statement, I have not taken into account different string length. I have added the code that deals with this scenario as well as a unit test

Co-authored-by: Ariel Shaqed (Scolnicov) <[email protected]>

N-o-Z · 2024-06-09T18:29:43Z

Not sure about this code. We should find a way to test this very precisely.

Thanks for the review.
I understand the concern, however I'm missing what exactly is missing in terms of confidence.
I've added additional unit tests for the walk function itself. The flows are extensively tested due to the recent work we did with bug fixes. I've also manually verified the performance improvement and documented it in the description.
If there are any other specific concerns - please let me know

Looks like it found somethine almost immediately :-/ AFAIU tests will run _existing_ failures in testdata/fuzz. You can fuzz more by running something like: ```sh $ go test -v ./pkg/local/ -fuzz FuzzWalkS3 --fuzztime 5m === RUN TestDiffLocal === RUN TestDiffLocal/t1_no_diff === RUN TestDiffLocal/t1_modified === RUN TestDiffLocal/t1_local_before === RUN TestDiffLocal/t1_local_after === RUN TestDiffLocal/t1_hidden_changed --- PASS: TestDiffLocal (0.00s) --- PASS: TestDiffLocal/t1_no_diff (0.00s) --- PASS: TestDiffLocal/t1_modified (0.00s) --- PASS: TestDiffLocal/t1_local_before (0.00s) --- PASS: TestDiffLocal/t1_local_after (0.00s) --- PASS: TestDiffLocal/t1_hidden_changed (0.00s) === RUN TestWalkS3 === RUN TestWalkS3/reverse_order === RUN TestWalkS3/file_in_the_middle === RUN TestWalkS3/dirs_at_the_end === RUN TestWalkS3/files_mixed_with_directories --- PASS: TestWalkS3 (0.00s) --- PASS: TestWalkS3/reverse_order (0.00s) --- PASS: TestWalkS3/file_in_the_middle (0.00s) --- PASS: TestWalkS3/dirs_at_the_end (0.00s) --- PASS: TestWalkS3/files_mixed_with_directories (0.00s) === RUN TestWriteIndex --- PASS: TestWriteIndex (0.00s) === RUN TestReadIndex --- PASS: TestReadIndex (0.00s) === RUN TestFindIndices --- PASS: TestFindIndices (0.00s) === RUN FuzzWalkS3 fuzz: elapsed: 0s, gathering baseline coverage: 0/47 completed failure while testing seed corpus entry: FuzzWalkS3/0345f16af6907ab1 fuzz: elapsed: 0s, gathering baseline coverage: 0/47 completed --- FAIL: FuzzWalkS3 (0.03s) --- FAIL: FuzzWalkS3 (0.00s) diff_test.go:323: Error Trace: /home/ariels/dev/lakeFS/pkg/local/diff_test.go:323 /home/ariels/sdk/go1.21.3/src/reflect/value.go:596 /home/ariels/sdk/go1.21.3/src/reflect/value.go:380 /home/ariels/sdk/go1.21.3/src/testing/fuzz.go:335 Error: Not equal: expected: []string{"imported 0", "imported/0"} actual : []string{"imported/0", "imported 0"} Diff: --- Expected +++ Actual @@ -1,4 +1,4 @@ ([]string) (len=2) { - (string) (len=10) "imported 0", - (string) (len=10) "imported/0" + (string) (len=10) "imported/0", + (string) (len=10) "imported 0" } Test: FuzzWalkS3 === NAME FAIL exit status 1 FAIL github.com/treeverse/lakefs/pkg/local 0.038s ``` Note that Go only finds a _first_ bug - but at least it tries to minimize it.

arielshaqed

I believe further testing is required. So I pushed some fuzzing code; I think it found a bug. I guess we need to fix either the fuzzer or the code. But I would like us to have some fuzzing here.

N-o-Z · 2024-06-11T10:12:55Z

I believe further testing is required. So I pushed some fuzzing code; I think it found a bug. I guess we need to fix either the fuzzer or the code. But I would like us to have some fuzzing here.

@arielshaqed Thanks for the test! I'm reverting the previous change as this is the root cause of the bug!

N-o-Z · 2024-06-13T13:41:19Z

@arielshaqed added a priority queue and more unit tests

…kectl-local-diff-slowness-7643

arielshaqed

Thanks, neat!

Let's also fuzz for ~30 minutes.

arielshaqed · 2024-06-16T19:13:18Z

cmd/lakectl/cmd/fs_upload.go

+			Die("failed to stat source", 1)
+		}
+
+		if !recursive || !stat.IsDir() { // Ignore recursive if source is a file and not a directory


I don't understand the code, but I didn't go through all the nooks and crannies. Suppose !recursive && stat.IsDir(). Then we don't perform this single-object upload, and instead go to l. 53 which says "try recursive upload". Do we need to fix the comment, or will this really recursively upload directories just because they're directories?

If !recursive && stat.IsDir() we will get the error:

read <path>: is a directory

We can explicitly check this matrix and fail if this makes it more clear.

arielshaqed · 2024-06-16T19:14:11Z

esti/lakectl_test.go

-		require.Contains(t, sanitizedResult, "Downloaded: 0")
-		require.Contains(t, sanitizedResult, "Uploaded: 1")
-		require.Contains(t, sanitizedResult, "Removed: 0")
+		RunCmdAndVerifySuccessWithFile(t, Lakectl()+" fs upload --recursive -s files/ro_1k lakefs://"+repoName+"/"+mainBranch+"/"+vars["FILE_PATH"]+" -s files/ro_1k", false, "lakectl_fs_upload", vars)


However we answer my above misunderstanding, I'd appreciate a test that a non-recursive upload of a directory does... whatever it should.

It does - it fails :)
Adding a test to cover this scenario 👍🏽 (we have a similar scenario that expects failure on the server side)

arielshaqed · 2024-06-16T19:16:22Z

pkg/local/diff.go

+			return nil
+		}
+		if info.IsDir() {
+			// TODO: We don't return dir results for the listing, how will this effect directory markers, and can we even support directory markers?


Can we open an issue for this?

arielshaqed · 2024-06-16T19:16:52Z

pkg/local/diff.go

+		}
+		if info.IsDir() {
+			// TODO: We don't return dir results for the listing, how will this effect directory markers, and can we even support directory markers?
+			// Save encountered directories in a sorted queue and compare them with the first appearance of an file in that level


Suggested change

// Save encountered directories in a sorted queue and compare them with the first appearance of an file in that level

// Save encountered directories in a priority queue and compare them with the first appearance of an file in that level

arielshaqed · 2024-06-16T19:18:22Z

pkg/local/diff.go

+			return filepath.SkipDir
+		}
+
+		heap.Init(&dirQueue)


Why do we need this call? This is a really inefficient call, it takes time linear in the size of heap. When using a heap as a priority queue it is not required: the heap invariants are always kept.

You are right, it's not needed

arielshaqed · 2024-06-16T19:22:20Z

pkg/local/diff.go

+			dir := heap.Pop(&dirQueue).(string)
+			if p > dir {
+				if err = WalkS3(dir, callbackFunc); err != nil {
+					return err
+				}
+			} else { // Put it back in its place
+				heap.Push(&dirQueue, dir)
+				break
+			}


This adds a $\Omega(log n)$ factor to every iteration. Why do we always remove the first heap element? Just implement a "Peek" or "Top" method which returns element 0 of the heap array.

arielshaqed · 2024-06-16T19:24:21Z

pkg/local/diff.go

+		}
+
+		heap.Init(&dirQueue)
+		for dirQueue.Len() > 0 {


We can and should run this loop even for a directory, so before l. 203; you'd only have to compare the "normalized" name, which is p for a file and p+"/" for a directory. That would keep the heap smaller, which is always helpful.

I'm not sure I understand the comment. That's exactly what this code is doing

arielshaqed · 2024-06-16T19:27:13Z

pkg/local/sorted_queue.go

+package local
+
+// A SortedQueue implements heap.Interface and holds strings.
+type SortedQueue []string


So why do all the methods use any and not string?

Required by the heap interface

arielshaqed · 2024-06-16T19:28:24Z

pkg/local/sorted_queue.go

+	return (*pq)[i] < (*pq)[j]
+}
+
+func (pq *SortedQueue) Swap(i, j int) {


As above, you could add

Suggested change

func (pq *SortedQueue) Swap(i, j int) {

func (pq *SortedQueue) Top() string {

return pq[0]

}

func (pq *SortedQueue) Swap(i, j int) {

package heap explicitly says that "The minimum element in the tree is the root, at index 0. "

arielshaqed · 2024-06-16T19:29:28Z

pkg/local/sorted_queue.go

+package local
+
+// A SortedQueue implements heap.Interface and holds strings.
+type SortedQueue []string


It's a PriorityQueue :-/ Let's rename after everything else is done, otherwise GitHub becomes a mess.

Modified the type name, I'll modify the file name when we're finished

arielshaqed

(Not approving because of some minor issues with recursive flag behaviour and efficiency.)

arielshaqed

Thanks! Looks really useful and fast.

Before committing, please do clean up the string-heap interface: the word "string" appears in the type name, so the word "any" should not appear in any type signature.

Also a comment on early-exits, but that one is your call.

arielshaqed · 2024-06-18T08:58:53Z

pkg/local/diff.go

 			if p > dir {
+				heap.Pop(&stringHeap) // remove from queue


Can we use stringHeap.Pop here (and below)?

We can't because it is the heap's Pop and Push logic that actually re-organizes the tree as part of the operation. the stringHeap object itself is rather "dumb".
We have to maintain the interface which returns any, otherwise we could not use the heap functionality

See https://pkg.go.dev/container/heap#Interface

arielshaqed · 2024-06-18T09:00:19Z

pkg/local/sorted_queue.go

-// A SortedQueue implements heap.Interface and holds strings.
-type SortedQueue []string
+// A StringHeap is a min-heap of strings
+type StringHeap []string


I don't understand why any method of this object ever takes an any argument: it holds only strings, which is fine. Why do we want to cast?

We have to maintain the interface which returns any, otherwise we could not use the heap functionality
See: https://pkg.go.dev/container/heap#Interface

arielshaqed · 2024-06-18T09:01:51Z

pkg/local/diff.go

+			} else {
 				break
 			}


As always, I would prefer to reverse test, write line 212 as

if p <= dir { break }

and lose a level of indentation.

(This is of course not required)

Fix: lakectl local diff slowness

0d7abfe

N-o-Z added bug Something isn't working include-changelog PR description should be included in next release changelog lakectl-local labels Jun 9, 2024

N-o-Z requested review from arielshaqed, guy-har and a team June 9, 2024 10:12

N-o-Z self-assigned this Jun 9, 2024

arielshaqed requested changes Jun 9, 2024

View reviewed changes

N-o-Z and others added 3 commits June 9, 2024 20:04

Fix upload

c14ffba

Update pkg/local/diff.go

1c826c9

Co-authored-by: Ariel Shaqed (Scolnicov) <[email protected]>

Add unit tests

f3facd5

N-o-Z requested a review from arielshaqed June 9, 2024 18:29

arielshaqed requested changes Jun 11, 2024

View reviewed changes

Add sorted queue

c8f78f4

N-o-Z requested a review from arielshaqed June 13, 2024 13:40

Merge remote-tracking branch 'refs/remotes/origin/master' into fix/la…

51b4c6f

…kectl-local-diff-slowness-7643

arielshaqed reviewed Jun 16, 2024

View reviewed changes

N-o-Z mentioned this pull request Jun 18, 2024

How do we support directory markers for lakectl local #7878

Open

CR fixes

fac7c60

N-o-Z requested a review from arielshaqed June 18, 2024 08:13

arielshaqed approved these changes Jun 18, 2024

View reviewed changes

CR Fixes last

2c37711

N-o-Z merged commit 5630d85 into master Jun 18, 2024
35 checks passed

N-o-Z deleted the fix/lakectl-local-diff-slowness-7643 branch June 18, 2024 12:28

	// Save encountered directories in a sorted queue and compare them with the first appearance of an file in that level
	// Save encountered directories in a priority queue and compare them with the first appearance of an file in that level

Fix: lakectl local diff slowness #7842

Fix: lakectl local diff slowness #7842

Conversation

N-o-Z commented Jun 9, 2024 • edited Loading

Change Description

Background

Bug Fix

Testing Details

Breaking Change?

Additional info

github-actions bot commented Jun 9, 2024

E2E Test Results - DynamoDB Local - Local Block Adapter

arielshaqed left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Example

Possible fix

N-o-Z Jun 9, 2024 • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

N-o-Z commented Jun 9, 2024

arielshaqed left a comment

Choose a reason for hiding this comment

N-o-Z commented Jun 11, 2024

N-o-Z commented Jun 13, 2024

arielshaqed left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

arielshaqed left a comment

Choose a reason for hiding this comment

arielshaqed left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

N-o-Z commented Jun 9, 2024 •

edited

Loading

N-o-Z Jun 9, 2024 •

edited

Loading