Skip to content

Boot spends 3.1s of 6.8s running a migration check that finds nothing, on every task start #205

Description

@Bccorb

Measured on the production task in fells-code/seamless-iac, from the container log:

+0.00s  Generating JWKS keys
+0.29s  JWKS keys ready
+0.29s  Running migrations...
+3.36s  No migrations were executed, database schema was already up to date
+3.37s  npm notice  New major version of npm available! 11.16.0 -> 12.0.2
+3.78s  > node dist/server.js
+5.41s  DB connection established
+6.78s  Server online

Three things in validateEnvs.sh cost about 55% of that, and none of them do work most of the time.

1. Migrations run on every task start, 3.07s, almost always to do nothing

run_migrations boots a second Node process, loads Sequelize CLI and the ORM, parses config, connects to the database, reads SequelizeMeta, finds nothing pending, and exits. 3.07s of the 6.78s boot, every start, forever.

There is also a correctness problem hiding behind it. portal-auth runs desiredCount: 2 with autoscaling above that, so every task races to migrate. That is invisible today because the migrations are idempotent no-ops, but a real migration during a scale-out or a rolling deploy means two processes applying the same schema change concurrently.

Worth keeping the property the current design is protecting: refusing to start against an un-migrated schema is correct, and a deploy that silently runs new code against an old schema is worse than a slow boot. The fix is to move migrations to a one-off task run once per deploy, not to drop the guard.

2. exec npm run start wraps node in npm

The npm notice above is npm doing an update check during boot. package.json has:

"start": "node dist/server.js"

so npm is a whole Node program loaded to exec one command, costing ~0.37s and a process. exec node dist/server.js is equivalent, and also puts the server at PID 1 rather than behind npm, which is better for SIGTERM handling during ECS draining.

3. initKeys.js is a third Node process

0.29s. Small, but it is a third cold V8 start before the server begins. Worth folding into server startup if that is straightforward.

Why it matters beyond 3.7 seconds

Node process startup is close to pure CPU. On the shared cluster these boots show up as CPU spikes of 70 to 100% of a 0.5 vCPU task, against a steady state under 2%:

20:12  avg  1.54%  max  4.67%
20:13  avg  9.61%  max 70.57%   <- task start
20:14  avg  7.26%  max 73.12%   <- second task start
20:15  avg  1.58%  max  4.96%

Those spikes are why fells-code/seamless-iac#99 could not shrink the tasks from 512/1024 to 256/512, worth about $59/mo. Halving to 0.25 vCPU roughly doubles boot, and the concern was a deploy failing to converge inside the health check grace window.

Cutting boot from 6.8s to around 3s would make 0.25 vCPU faster than today's boot at twice the CPU, which removes that objection. That saving is four times larger than the ARM migration already done, so this is the highest-value startup work available.

Suggested order

  1. exec node dist/server.js instead of exec npm run start. One line, no behaviour change.
  2. Move migrations out of the container entrypoint to a one-off task. Biggest win and fixes the concurrent-migration race.
  3. Fold initKeys into server start if it is cheap to do.

Re-measure afterwards, and re-open seamless-iac#99 with the new numbers rather than assuming the saving is unlocked.

Related

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

    P3FixesbugSomething isn't working

    Type

    No type

    Projects

    No projects

      Milestone

      No milestone

      Relationships

      None yet

      Development

      No branches or pull requests

      Issue actions