Test test_threshold_based_eviction is flaky (unexpectedly on-demand downloading remote layer remote)

[bayandin]

test_threshold_based_eviction#test_threshold_based_eviction:

Error message:

AssertionError: assert not ['2023-05-04T14:42:57.586772Z  WARN eviction_task{tenant_id=a4f5620478d84e0feff340fb651f8bfb timeline_id=f0d71e20c1b6f...AC0000400C00FFFFFFFF-000000067F000032AC000040140000000008__0000000001696070-0000000003DC76E9 for task kind Eviction\n']

Pageserver warning itself (I broke the long line into several smaller ones to make it more readable):

2023-05-04T14:42:57.586772Z  
WARN eviction_task{tenant_id=a4f5620478d84e0feff340fb651f8bfb timeline_id=f0d71e20c1b6fcbc94a3d391259a7fc1}:
eviction_iteration{policy_kind="LayerAccessThreshold"}: 
unexpectedly on-demand downloading remote layer remote f0d71e20c1b6fcbc94a3d391259a7fc1/000000067F000032AC0000400C00FFFFFFFF-000000067F000032AC000040140000000008__0000000001696070-0000000003DC76E9 for task kind Eviction

See https://neon-github-public-dev.s3.amazonaws.com/reports/pr-4092/debug/4883913165/index.html#suites/3fc871d9ee8127d8501d607e03205abb/2cff07ef9a017a6

[problame]

We also have a small number of unexpected on-demand downloads in Prod.

The unexpected on-demand downloads happen shortly after we have CPU usage spikes. (I'd guess it's irrelevant that these usage spikes are ca 1 day apart?)

[problame]

Strong correlation with increase in logical size time spent

[problame]

Zooming into one of them, just to demonstrate the correlation

[koivunej]

From @bayandin's gist:

/github/home/.cache/pypoetry/virtualenvs/neon-_pxWMzVK-py3.9/lib/python3.9/site-packages/allure_commons/_allure.py:221: in __call__
    return self._fixture_function(*args, **kwargs)
test_runner/fixtures/neon_fixtures.py:1122: in neon_env_builder
    yield builder
test_runner/fixtures/neon_fixtures.py:850: in __exit__
    self.env.pageserver.assert_no_errors()
test_runner/fixtures/neon_fixtures.py:1691: in assert_no_errors
    assert not errors
E   AssertionError: assert not ['2023-05-16T13:41:03.876833Z  WARN eviction_task{tenant_id=92484835d2e280c5a66c3264c35b1d0f timeline_id=e9239d7e2cdba...AC0000400C0200000000-000000067F000032AC000040140000000022__00000000036FE179-0000000003DCB789 for task kind Eviction\n']

• test_threshold_based_eviction[release-pg14]

[problame]

We decided to put this on hold until https://github.com/orgs/neondatabase/projects/38 (async get_value_reconstruct_data) is merged and see whether that fixes the issue.

Here's a dump of my internal notes on this issue:

---

• Hypothesis the logical size computation does IOs, and it does them inside the tokio executor threads ⇒ we only do 8 IOs at a time, and, block the executor threads while doing int ⇒ other tasks get delayed ⇒ …???… ⇒ imitate accesses come too late ⇒ evictions

  • without validating hypothesis, started attempt to convert logical size computation to async ⇒ needs to convert IOs to async
    • That's project https://github.com/orgs/neondatabase/projects/38
  • So, do the above in reverse order
  • should try to validate hypothesis first, though, but how? Can we increase the number of tokio threads?
  • Also, isn’t there a semaphore for logical size computation that prevents it from happening concurrently? So, are we actually only blocking 1 tokio thread?
    • Can we get the wall clock time that tokio executor threads (not tokio fs threads) are spending in read / write system calls (to filesystem, not sockets) and compare it against total wall clock time passed in a given interval?
  • Ah hm actually only the synthetic size calculation imitation rate-limits, but, the last_record_lsn size calculation doesn’t. So, 1000 timelines doing it at a same time will contend for the $ncpus executor threads.

• should try to validate hypothesis first, though, but how? Can we increase the number of tokio threads?

• Also, isn’t there a semaphore for logical size computation that prevents it from happening concurrently? So, are we actually only blocking 1 tokio thread?

  • Can we get the wall clock time that tokio executor threads (not tokio fs threads) are spending in read / write system calls (to filesystem, not sockets) and compare it against total wall clock time passed in a given interval?

• Ah hm actually only the synthetic size calculation imitation rate-limits, but, the last_record_lsn size calculation doesn’t. So, 1000 timelines doing it at a same time will contend for the $ncpus executor threads.

• Idea for the ??? in above Hyptohesis:

  • timeline imitate accesses never get evicted, that’s for sure, because we get now before we imitate the acceses
  • but, there’s also the tenant imitate accesses. we only do them once per tenant, so, tenants with multiple timelines can interleave here
  • what can happen???

[arssher]

One more time https://neon-github-public-dev.s3.amazonaws.com/reports/pr-4731/5585100850/index.html#categories/c1b51b30b43e587922d3feecc3c7f502/c11fb9d88c3ae9b/