Skip to content

Checkpoint: Entitlements CI performance profiling and optimizations #80

Open
Open
Checkpoint: Entitlements CI performance profiling and optimizations#80

Description

@hosom
hosom
opened on Sep 12, 2026

Purpose

This issue is a checkpoint for the ongoing effort to understand and reduce the wall-clock time of the entitlements-default CI calculation in github/entitlements. It is intended to contain enough context for a new engineer or agent to resume the work without reconstructing the investigation from scratch.

The short version:

  • The calculation was spending substantial CPU and allocation time in avoidable local Ruby work, especially runtime contracts and repeated traversals.
  • GitHub, AAD, LDAP, and cache/network waits still dominate the live job after the local Ruby optimizations.
  • Several logic flaws have been identified and fixed in separate PRs.
  • The current cumulative benchmark is running in draft github/entitlements#141320 using locally built and vendored gems.

Current status

As of September 14, 2026:

  • Merged and released: Reuse successful LDAP base searches #79 as entitlements-app 1.2.3, github/octomsgraph#525 as Octomsgraph 0.11.1, and github/entitlements-github-plugin#305 as entitlements-github-plugin 1.2.5.
  • Merged into Entitlements: github/entitlements#141424 vendors Octomsgraph 0.11.1.
  • Awaiting merge into Entitlements: github/entitlements#141452 vendors entitlements-app 1.2.3; it is approved and all CI passes. github/entitlements#141457 vendors entitlements-github-plugin 1.2.5; the lockfile failure is fixed, current CI is green except for the still-running full Entitlements calculation, and review is required.
  • entitlements-app 1.2.3 also invalidates the known-existence and DN read caches after successful LDAP deletion, addressing review feedback discovered during the optimization.
  • github/entitlements-caches#82 is deployed even though the PR remains open. It requests $top=999 during Graph group-membership refreshes.
  • github/entitlements-aad-plugin#282 adds the same page size for direct-to-Graph deployments; it is not required for traffic routed through the dedicated cache.
  • Optimize entitlement calculation hot paths #77 and Remove contracts from entitlement calculation hot paths #78 remain open. They contain the largest measured local CPU/allocation improvements and still need to be brought up to date and merged.
  • The cumulative benchmark remains draft github/entitlements#141320 and must not be merged.

The fastest warmed cumulative benchmark is run 34872508538, attempt 3, at 419.92 seconds:

  • production AAD: 124.47s
  • testing AAD: 20.44s
  • subscriptions AAD: 14.58s
  • Proxima GitHub org/JIT: 64.79s
  • github.com/github/teams: 41.16s
  • main GitHub org/JIT: 23.65s

The $top=999 cache deployment is behaviorally verified in Datadog. Large groups that previously required 48-61 Microsoft Graph pages now require 5-6 pages. A deployment restarts the cache's in-memory state, so the first post-deploy run is a cold-cache warmup and should not be compared with warmed runs.

The persistent GitHub REST benchmark, run 34888173055, showed:

  • Proxima GitHub org target: 64.79s -> 6.70s (89.7% faster)
  • main github.com/github/org target: 23.65s -> 7.72s (67.4% faster)
  • github.com/github/teams: 41.16s -> 40.20s (effectively unchanged)

The total for that run was cache/noise affected and not a clean aggregate comparison: all prefetch, validation, and calculation took 616.51s. The isolated organization timings are the useful evidence.

Production Datadog data does not yet show a declining general calculation-time trend. Successful calculate_total operations averaged 21.3 minutes from September 9-11 and 28.9 minutes from September 12-14, a 35.4% increase dominated by cold-cache and network variability. The two newest improvements are not represented in production yet: #305 has not merged, and 1.2.3 is still landing through github/entitlements#141452.

Related pull requests

PR Base Purpose Measured result/status
#77 main Consolidates repeated calculation/filter work, avoids repeated partitioning, improves recursive cache keys/config propagation, and replaces array-backed membership checks. Synthetic median 64.99s -> 19.44s; allocations ~423M -> 75.8M. Open and behind main; update before merge.
#78 #77 branch Removes expensive runtime contract wrappers from recursive calculation internals while retaining contracts at public boundaries. Synthetic median 19.44s -> 13.68s; allocations 75.8M -> 34.7M. With YJIT: 11.28s. Open and clean on its stacked base.
#79 main Records successfully searched LDAP bases, answers later exists? checks from that knowledge, and invalidates LDAP caches after successful deletion. Merged and released in entitlements-app 1.2.3. Live cumulative attempt removed 261 searches: ~531 -> 270.
github/entitlements-github-plugin#304 main Fetches github.org_members once in role_to_group instead of once for keys and again per username. Removes accidental O(n^2) deep contract validation. Closed as superseded after being stacked into github/entitlements-github-plugin#305. Unprofiled live average improved 495.22s -> 483.24s (~12s / 2.4%).
github/octomsgraph#525 main Explicitly starts and reuses the existing Net::HTTP object. On transport failure it closes and re-raises without automatically replaying non-idempotent requests. Merged and released as 0.11.1.
github/entitlements-caches#82 main Requests 999 members per Microsoft Graph page when refreshing the AAD cache. Deployed. Large-group refreshes fell from 48-61 pages to 5-6.
github/entitlements-aad-plugin#282 main Requests 999 members per page for direct Graph access. Open; not required for the dedicated cache route.
github/entitlements-github-plugin#305 main Combines organization-member reuse with persistent HTTP connections for paginated Octokit REST reads. Merged and released as 1.2.5. Proxima org target improved 64.79s -> 6.70s; the organization-member reuse independently saved about 12s.
github/entitlements#141452 master Vendors the official entitlements-app 1.2.3 release. Open, approved, all CI passes; ready to merge.
github/entitlements#141457 master Vendors the official entitlements-github-plugin 1.2.5 release and persistent HTTP dependencies. Open; dependency-lock failure fixed. Fast checks pass, full Entitlements calculation is still running, and review is required.
github/entitlements#141320 master Draft live-fire benchmark PR. Vendors locally built optimization gems and includes optional StackProf/ruby-prof CI tooling. Intentionally non-mergeable as production code because locally built gems lack package provenance; expected attestation failure.

Important commits:

Benchmark results so far

Local synthetic calculation-only benchmark

The local benchmark uses production-shaped synthetic people data and a calculation-only backend so it can isolate local Ruby calculation from remote writes and most network behavior.

Variant Calculation time Allocation result
Original baseline 64.99s median ~423M objects
#77 logic changes 19.44s median 75.8M objects
#77 + #78 contracts 13.68s median 34.7M objects
#77 + #78 + YJIT 11.28s observed Not separately summarized

YJIT by itself reduced the original synthetic median from 64.99s to 51.35s, approximately 21%, with about 1.6% additional memory. Conservative GC environment tuning was neutral. YJIT is worthwhile, but the logic fixes are substantially more valuable.

Local scripts are currently uncommitted in ~/Documents/entitlements:

  • script/dev/generate-synthetic-people
  • script/dev/profile-calculations
  • script/dev/support/profile_backend.rb
  • script/dev/README.md

The local benchmark used Ruby 3.3.12 on arm64 macOS. Live CI uses Ruby 3.4.9, so compare relative trends rather than treating local absolute times as CI predictions.

Live unprofiled CI benchmark

The live-fire benchmark is the real no-op deployment in entitlements-default. Read the application's own timing line rather than the full Actions job duration:

Finished all calculations in <seconds>

Known results:

Variant Live calculation result
Earlier successful-run baseline ~626s median across six runs; historical range roughly 429-866s
#77 + #78 app gem 494.56s and 495.87s; 495.22s average
#77 + #78 + provider #304 483.24s average
Cumulative app/provider/LDAP/Octomsgraph, attempt 1 604.58s, invalid as a clean comparison because production AAD paid 321.35s of cache refresh work
Best warmed cumulative run after AAD pagination deployment 419.92s
Cumulative run with persistent GitHub REST 616.51s total, cache/noise affected; isolated GitHub org targets improved by 67-90%

The best clean live result before the current cumulative run represents about 142.8 seconds / 22.8% improvement from the 626-second baseline. Network and cache state are noisy enough to mask local CPU improvements, so preserve per-target timing context for every comparison.

How the live benchmark is assembled

Draft github/entitlements#141320 vendors locally built gems under vendor/cache while retaining the released version numbers. The lockfile remains on the generic ruby platform.

Current cumulative artifacts:

  • entitlements-app-1.2.2.gem, containing the cumulative app changes used by the benchmark
  • entitlements-github-plugin-1.2.5.gem
    • built from combined github/entitlements-github-plugin#305, including the former #304 change
    • SHA-256: d6b215d434e7947f4726f5db1773f00f67a0ad21231438c150dc31839bbb2a40
  • faraday-net_http_persistent-2.3.1.gem
    • SHA-256: 23ffba37d6a27807a10f033d01918ec958aa73fa6ff0fccfbcd5ce2d2e68fca3
  • net-http-persistent-4.0.8.gem
    • SHA-256: ef3de8319d691537b329053fae3a33195f8b070bbbfae8bf1a58c796081960e6
  • official octomsgraph-0.11.1.gem
    • SHA-256: 53e0d992683ee4238fc02cd92c920c2982b63df0e314b811bda606a969de2c0e
  • StackProf 0.2.28 and ruby-prof 2.0.5 remain vendored for optional branch-only profiling.

Do not allow local Bundler to replace this lockfile section:

PLATFORMS
  ruby

A previous macOS bundle operation changed it to arm64-darwin-25, which broke Linux CI/private package resolution.

The benchmark PR is deliberately a draft and should not be merged with these local artifacts. Its gem-attestation check fails as expected because the locally built gems are unattested.

Profiling methodology and artifacts

StackProf CPU sampling

The benchmark branch can wrap the real no-op deployment with StackProf at a 1 ms CPU interval. It uploads:

  • raw StackProf dump
  • top self-time report
  • top total-time report
  • D3 flamegraph

Runs:

Initial app profile findings:

  • 194,071 total CPU samples
  • 32,864 GC samples, 16.93%
  • Contracts::Builtin::HashOf#valid?: 17.7% self CPU, 42.0% total CPU
  • Contracts::CallWith#call_with_inner: below 79.8% of samples
  • dominant path: GitHubOrg::Provider#read -> role_to_group -> repeated org_members

Provider #304 before/after profile:

  • total samples: 194,071 -> 93,125, down 52.0%
  • HashOf#valid? self: 34,349 -> 802, down 97.7%
  • HashOf#valid? total: 81,471 -> 1,939, down 97.6%
  • Array#map self: 32,203 -> 1,452, down 95.5%
  • contract-wrapper total: 154,808 -> 68,586, down 55.7%
  • GC samples: 32,864 -> 18,541, down 43.6%

StackProf is useful for CPU/allocation hot paths but cannot accurately attribute blocked wall time or individual network latency distributions.

ruby-prof wall-clock tracing

ruby-prof 2.0.5 is available in the benchmark branch and can profile in wall mode using the multi-printer. It uploads flat, graph, graph HTML, stack HTML, and flamegraph reports.

Profile run: 34668794691

The profiler added severe overhead: calculation took approximately 1,811 seconds versus the then-current ~483-second unprofiled average, about 3.75x slower. Treat method call counts and broad ranking as useful; do not treat absolute profiled timings as normal production latency.

Important aggregate findings:

  • AAD Graph/Octomsgraph: 1,883 requests, 961.9 profiled seconds, 510.9 ms mean
  • GitHub REST/cache through Faraday: 559 requests, 183.7 seconds, 328.7 ms mean
  • GitHub GraphQL: 227 requests, 105.4 seconds, 464.5 ms mean
  • Stafftools HMAC HTTP: 31 requests, 4.9 seconds, 157.9 ms mean
  • application LDAP searches across threads: approximately 531
    • 269 during prefetch
    • 261 calculation-time exists? calls
    • approximately one other search
  • IO#wait_readable: 1,241 seconds / 68.3% of the main profiled thread
  • Net::HTTP#do_start: 2,650 calls for 2,708 HTTP requests

The original benchmark comment reported only 262 LDAP searches because it looked at the main calculation thread. The corrected total is approximately 531 across prefetch and calculation threads.

Profiling is currently disabled in the branch. Enable only one profiler at a time through the conditional logic in script/ci-tests/2-noop-deploy.sh; do not benchmark normal wall-clock performance with a profiler enabled.

Important technical findings

1. Calculation logic and contracts

Object profiling initially showed roughly 423 million allocations. Runtime contract wrappers dominated allocation samples. #77 removes repeated work in calculation/filter/cache paths, and #78 removes contracts from recursive internals while retaining boundary validation.

The biggest provider-specific flaw was in GitHubOrg::Provider#role_to_group: it called github.org_members once to get keys and then once per username. The cached hash has a deep return contract, so each accessor call revalidated the entire membership structure. This created accidental O(n^2) contract work. github/entitlements-github-plugin#304 fetches the hash once and traverses the local value.

2. LDAP object caching did not mean connection caching

Entitlements::Service::LDAP.new_with_cache caches a Net::LDAP object, but net-ldap 0.20.0 opens, binds, yields, closes, and discards a connection for every operation unless calls execute inside Net::LDAP#open.

A broad persistent LDAP session is risky because prefetch has concurrent worker threads, Net::LDAP is not safe for simultaneous operations on one open connection, and a connection could sit idle through long GitHub/AAD phases.

#79 takes the safer path: a successful prefetch search proves its exact base exists, so the later create_if_missing check can return true without another LDAP request. Failed searches do not establish existence. Attempt 1 of the cumulative live run confirmed the expected reduction from ~531 to 270 searches.

3. Octomsgraph retained an HTTP object but not its socket

Before github/octomsgraph#525, the client constructed one Net::HTTP object but called request without start. Net::HTTP therefore started and closed a connection for every request.

#525 starts the existing object lazily and reuses it. Transport errors close the failed connection and are re-raised. The client deliberately does not automatically replay the request because POST/PATCH failures can be ambiguous; existing callers decide whether an operation is safe to retry.

Octomsgraph already supports Microsoft Graph batch requests of up to 20 operations. The AAD provider currently sends group reads serially. Batching may produce a larger future improvement than keep-alive, but pagination, response mapping, partial errors, retries, and cache behavior make it a broader change.

4. GitHub REST and GraphQL connection behavior

The custom GitHub GraphQL path already starts and reuses a Net::HTTP connection and resets it on failure. The profile still showed 169 connection starts for 227 GraphQL requests, likely because separate provider/service instances each own a connection and because servers may close sockets.

GitHub REST uses Octokit/Faraday with the ordinary faraday-net_http adapter, which generally opens one connection per request. A future experiment could use faraday-net_http_persistent, but this requires a dependency and middleware configuration change and should be measured separately.

5. There are two different AAD caches

Do not confuse these layers:

  1. Predictive auditlog cache
    • loaded from github/entitlements-auditlog
    • accessed through Entitlements::Data::Groups::Cached
    • skips an AAD endpoint call when expected state is already known
  2. Kubernetes AAD cache
    • the entitlements-caches-aad service
    • an in-memory hash in a long-running Kubernetes pod
    • synchronously refreshes expired values from Microsoft Graph

The approximately 48% figure was predictive auditlog coverage, not Kubernetes cache efficiency:

Target Configured groups Auditlog entries Coverage
Production AAD 1,552 743 47.9%
Testing AAD 1,552 743 47.9%
Subscription target 210 106 50.5%
Total 3,314 1,592 48.0%

There were no stale auditlog entries in the analyzed paths. The GitRepo auditor intentionally does not create a missing auditlog file when the calculated group is empty. This likely accounts for most of the 1,722 configured groups without predictive-state files. Those groups must call the AAD endpoint on every run even when unchanged.

During the ruby-prof window, Datadog recorded across all Kubernetes AAD-cache traffic:

  • 5,111 hits
  • 172 expired entries/refetches
  • no cold misses
  • 96.7% hit rate among hit/expired lookups
  • average in-process hit work around 0.009 ms
  • average expired refresh around 8.1 seconds

These metrics cannot be isolated exactly to one CI run because they lack a run/client tag. Cache state can dominate a live benchmark, as cumulative attempt 1 demonstrated.

Where live calculation time remains

Across several exact calculation windows, the largest target-level cumulative areas included:

  • apps/proxima/github/github/teams: 407.2 seconds across five runs, 81.4 seconds/run average
  • apps/proxima/github/github/org/always-on: 273.2 seconds cumulative, 54.6 seconds/run
  • apps/azure_aad: 175.0 seconds cumulative, 35.0 seconds/run
  • AAD testing target: 140.3 seconds cumulative
  • main GitHub org/JIT target: 139.9 seconds cumulative

Across four optimized runs, GitHub-backed providers averaged approximately 331.8 seconds combined per run. Network/cache variation can overwhelm a 10-50 second local optimization, so always examine both total calculation time and individual target intervals.

Local/session artifacts

If resuming on the same workstation/session, downloaded reports and unpacked sources are under:

~/.copilot/session-state/5b8ed060-ed02-4402-b5e1-af407bcb2f61/files/

Notable directories:

  • entitlements-profile-run-34653105966/
  • provider-profile-run-34659679178/
  • ruby-prof-run-34668794691/
  • entitlements-live-fire/
  • entitlements-app-cumulative-build/
  • octomsgraph-keepalive/
  • cumulative-run-34672637185.log
  • unpacked source trees for entitlements-app, AAD plugin, Octomsgraph, net-ldap, and GitRepo auditor
  • entitlements-auditlog-cache-analysis/

These paths are convenience copies, not durable shared documentation. The GitHub PRs, Actions runs, and this issue are the durable references.

Recommended next steps

  1. Finish landing the released gems.

    • Merge github/entitlements#141452 for entitlements-app 1.2.3.
    • Review and merge github/entitlements#141457 for entitlements-github-plugin 1.2.5 after the full calculation check finishes.
    • After deployment, compare warmed production calculate_total and the Proxima/main GitHub organization targets for several days.

  2. Bring Optimize entitlement calculation hot paths #77 and Remove contracts from entitlement calculation hot paths #78 to merge.

  3. Batch GitHub team cache misses.

    • github.com/github/teams is now the largest stable untreated benchmark target at 40.20s.
    • The benchmark performs 1,651 team reads: 1,595 predictive-cache hits and 56 real GraphQL reads.
    • The 56 reads are existing teams, not negative lookups. Batch cache-missing teams with GraphQL aliases, perhaps 10-20 teams per request, then paginate only large teams.
    • Reducing 56 serial requests to approximately 3-6 initial requests could plausibly recover 25-35 seconds.

  4. Address AAD refresh synchronization.

    • Page-size efficiency is fixed, but an expired cache entry still synchronously blocks the caller while every Graph page is fetched.
    • Evaluate per-group request coalescing to prevent duplicate concurrent refreshes.
    • Consider stale-while-revalidate separately; it has stronger consistency and operational tradeoffs.

  5. Improve benchmark/build iteration speed.

    • The benchmark Docker dependency layer takes roughly 11-12 minutes whenever vendored gems change.
    • A branch-scoped BuildKit GHA cache experiment was added, but changing the vendored gems invalidates that layer. Consider a benchmark-specific prebuilt dependency image or registry cache.

  6. Consider enabling YJIT in CI as a separate change.

    • Local evidence shows about 21% improvement on the original calculation and 17.5% on the optimized contract benchmark (13.68s -> 11.28s observed).
    • Measure memory and live CI behavior separately; Ruby versions differ between local and CI.

  7. Keep benchmark hygiene.

    • Profile only when collecting call paths/counts; disable profilers for wall-clock benchmarks.
    • Preserve PLATFORMS ruby in Gemfile.lock.
    • Record source commit and SHA-256 for every locally built gem.
    • Treat the benchmark PR's attestation failure as expected and never merge unattested local gems.

Useful benchmark comments

The draft benchmark PR has chronological comments covering the provider profile, request distribution, cache clarification, LDAP correction, linked optimization PRs, cumulative artifacts, and the noisy first cumulative run:

Activity

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Metadata

Metadata

Assignees

No one assigned

    Labels

    No labels
    No labels

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions