guardrails: attribution slow on dotcom

[keegancsmith]

Getting 5s+ attribution search times for search queries which should be very very fast. This is proving a bit tricky to track down due to unreliability in our traces at the moment.

[keegancsmith]

We are doing searches for large strings and the performance is surprisingly slow. I think it is zoekt that is just slow in this case. We are setting max repo match limits.

My current theory is that iterateNgrams is slow in this use case. This theory needs to be tested. But I believe we likely spend a long time here vs normal searches.

iterateNgrams constructs the document iterator based on the ngram index. To do this is looks up every ngram in the query (and possibly all casing) to find the rarest ngrams (or an example of an ngram which doesn't exist). Because the lookup for this is via a btree, this likely does a lot of random accesses across all shards.

I would suspect once the iterator has been constructed, it would likely then be fast for large queries since I would suspect large queries are more likely to contains two rare trigrams. Just finding those trigrams is the issue.

I'm trying to think up some SearchResults.Stats we can add or other observability to try confirm this.

@stefanhengl wdyt?

[stefanhengl]

I think your suspicion might be correct. The way we get the frequencies is just inefficient. We could store the frequencies in the btree, which would save us 1 read of the posting list's simple section. In addition we could sort the ngrams before searching for the frequencies. This should reduce the disk access because the ngrams in the buckets are sorted too.

EDIT:

We could store the frequencies in the btree

Right now we construct the btree on read. For the buckets, which remain on disk, we just reinterpret the existing ngram section. If we want to attach metadata to the items in the buckets we have to change the index format, because I assume we would like to store the frequency right next to the ngram instead of getting it from the simple section of the ngram's posting list.

Sorting the ngrams before we get the frequencies might already give us some benefits without changing the format.

[stefanhengl]

Assuming we are not saturating the disk, we could add some concurrency to frequency lookup in iterateNgrams.

[keegancsmith]

I spent a bunch of time adding general observability stuff to the search client, then I realised I can just look into our zoekt instrumentation since Zoekt seems to be the root cause. So did a query which took 5s. This is faster than I have been seeing but still too slow. It is likely faster thanks to turning on case sensitivity last night. Got this from honeycomb for that query:

{
  "Timestamp": "2023-06-22T07:47:31.590105624Z",
  "actor": "0",
  "category": "SearchAll",
  "duration_ms": 5189,
  "events": 4,
  "filematches": 2,
  "opts.estimate_doc_count": false,
  "opts.flush_wall_time_ms": 0,
  "opts.max_doc_display_count": 5,
  "opts.max_wall_time_ms": 59999,
  "opts.shard_max_match_count": 10000,
  "opts.shard_repo_max_match_count": 1,
  "opts.total_max_match_count": 100000,
  "opts.use_document_ranks": false,
  "opts.whole": false,
  "pod_name": "sourcegraph-frontend-8c6b48cb4-j8szf",
  "query": "(and case_content_substr:\"const data: Event = { ...JSON.parse(message.data), type: message.event }\" branch=\"HEAD\" rawConfig:RcOnlyPublic|RcNoForks|RcNoArchived)",
  "stats.content_bytes_loaded": 126962274,
  "stats.crashes": 0,
  "stats.file_count": 2,
  "stats.files_considered": 4423,
  "stats.files_loaded": 4307,
  "stats.files_skipped": 0,
  "stats.flush_reason": "none",
  "stats.index_bytes_loaded": 5659533,
  "stats.match_count": 2,
  "stats.ngram_matches": 7255,
  "stats.regexps_considered": 0,
  "stats.shard_files_considered": 0,
  "stats.shards_scanned": 8921,
  "stats.shards_skipped": 0,
  "stats.shards_skipped_filter": 537798,
  "stats.wait_ms": 0,
  "stream.total_send_time_ms": 0
}

Alright so when it comes to our options, they seem sub-optimal given we are not doing ranking. We don't need 100k results if we are only returning 5. I don't think this is the root cause of the slowness of this query but for more common patterns it will be an issue.

"stats.files_considered": 4423,
"stats.files_loaded": 4307,

These numbers are super low, which means we only attempted to search a very low number of files. So our slowness is related to index related options.

"stats.shards_scanned": 8921,
"stats.shards_skipped": 0,
"stats.shards_skipped_filter": 537798,

This means we ruled out the majority of shards. This does interact with the index to lookup which trigrams exist.

"stats.content_bytes_loaded": 126 962 274,
"stats.index_bytes_loaded":     5 659 533,

126MB of data is not a lot to do substring searches over. This will be somewhat random though which could account for the 5s time. 5MB of index is not much at all.

One surprising thing is that those stats give us an avg file size of 29kb which is large for code. For example the ts and tsx files in our monorepo hav an average size of 3.5kb. But I don't think that is the root cause.

I'm feeling much more confident in the idea this is related to how we lookup trigrams needing improvement. This is actually a place were bloom filters would be useful again.

I am going to add in a stastistic in zoekt to track how much work we do in matchtree construction to try and narrow this down.

[keegancsmith]

We could store the frequencies in the btree

Right now we construct the btree on read. For the buckets, which remain on disk, we just reinterpret the existing ngram section. If we want to attach metadata to the items in the buckets we have to change the index format, because I assume we would like to store the frequency right next to the ngram instead of getting it from the simple section of the ngram's posting list.

It would at least half the amount of IO we do which is great. But alone I don't think this is good enough.

Sorting the ngrams before we get the frequencies might already give us some benefits without changing the format.

Indeed I am thinking along this approach. Given in most cases we find a trigram which rules out the need to do the search, by implement a binary search with a sorted candidate set we will be more friendly to the page cache.

Assuming we are not saturating the disk, we could add some concurrency to frequency lookup in iterateNgrams.

I am unsure how much this would help, I always assume we are saturating the disk already. But this is a good idea to check.

[stefanhengl]

You could also just disable the btree locally and compare. This would be a smoking gun indeed.

[keegancsmith]

I added some attribution specific observability and had in my plans for today to:

• add a stat to zoekt related to ngram lookups
• reproduce locally

I don't think I'll get to the latter two today, so will attempt it on Monday. Below is full notes

*** TODO stat around ngram lookups
    SCHEDULED: <2023-06-26 Mon>
    - Rescheduled from "[2023-06-23 Fri]" on [2023-06-23 Fri 13:42]
This is just to confirm that this value is much higher. It doesn't really tell
us how the IO is behaving.
*** TODO try reproduce locally
    SCHEDULED: <2023-06-26 Mon>
    - Rescheduled from "[2023-06-23 Fri]" on [2023-06-23 Fri 13:42]
- [ ] get a large corpus running locally. Maybe snapshot prod which only has
  public code into a GCS bucket.
- [ ] reproduce an attribution search with same opts
- [ ] reproduce with btree turned off
*** TODO implement smart frequency lookup
This is something to try out once we can reproduce locally.

[keegancsmith]

This issue is still in progress. Since my last update on Friday I have mostly been focussed on helping out with the release of 5.1. However, I did send out a draft PR to discuss how to instrument zoekt here. It is a little trickier than I at first hoped. sourcegraph/zoekt#606

[keegancsmith]

tl;dr abandoning btree instrumentation and will just instrument ngram lookup counts. btree lookup should only cause at most 1 page fault.

btree and page alignment

the non-leaf nodes exist in memory. The lead nodes is where we do the binary search and that should represent a page. I don't think we actually do anything to make them page aligned, @stefanhengl mentioned he couldn't affect the number of page faults in his testing so didn't do this logic (if I remember what he said correctly).

Given we are doing the binary search on one page of data it isn't worth capturing how many accesses we do here. And to find the page we only access in memory data. Given both of those its likely only useful to track how many lookups we do in total, so do not need btree specific instrumentation.

I decided to go down the rabbit hole to work out how we could do page alignment if we wanted it. For mmap in zoekt we do what is called a NULL mmap of the file. We make the length aligned with page size (although I don't think this is necessary for NULL mmap). A NULL mmap means the OS picks where to start the memory, which means it will be page aligned. To confirm we do a NULL mmap I followed our mmap calls all the way down to the syscall, and confirmed the first argument (which is void *addr) was 0.

Out of interest, we can get hold of page size with os.Getpagesize() (and use it in our implementation of bufferSize). Given our mmap files are page aligned, we could probably construct the btree along page boundaries.

reproducing locally

Discussed doing with just one big repo. But we need lots of shards to reproduce. When looking at the stats you can see "stats.shards_skipped_filter": 537798 + "stats.shards_scanned": 8921 is the total number of shards in our cluster. IE it looks like our time is dominated by ruling out shards. We confirmed those two numbers equal the number of shards by checking the metric zoekt_shards_total.