The process started, both probes passed, and the first sign that the
schema did not match was a login failing with a driver-level encoding
error - go-admin#919, where an operator upgraded the binary and
restarted the API without running migrate. Nothing between those two
events had an opinion about the schema.
Readiness is where this belongs. Liveness asks "restart me", and a
process whose database is on the wrong schema comes back to the same
schema. Readiness asks "send me requests", and the answer is no. A
rolling update then stalls at the deploy - new instances never become
ready, the old ones keep serving - rather than at somebody's login, and
running migrate clears it without a restart because the check is
evaluated per request.
Any tenant database being behind fails the check, not only the one being
served: migrations are applied to every database in one run, so one
behind means that run did not finish, and serving the rest would let a
half-applied deploy look like a partial success.
A missing sys_migration table is nothing applied rather than an error.
That is a first deploy, where every migration is pending and the
operator can act on being told so.
The one test that matters is the one that cannot be written normally.
The registry is filled by init() in packages cmd/api does not import, so
a test that imported them to look at it would pass whatever the real
binary links - and a binary that links none of them gives a check that
reports every database current, forever, with every other test here
still green. TestTheServingBinaryLinksTheMigrationRegistry asks the
build instead, with a negative control so that a query matching
everything fails rather than passes.
Closes#920.
Whether the schema matches what the binary expects is answered by the
migration registry, which lives under cmd/. common/ has never imported
cmd/, and starting with this would put the shared layer behind the
command layer for one check.
Register instead, from where both are already in scope. A duplicate name
panics rather than appending: two checks under one name make the failing
one impossible to identify from the response body, and registering the
same one twice is a wiring mistake better heard at start-up than never.
The registered check is run through the same guard as the built-in ones,
so one that panics fails its check rather than taking down the probe
that asked.
Status answers what is registered, what is applied, and what is applied
while nothing registers it - and needs a database to do it. A readiness
check needs only the first half, and it already holds the databases it
is asking about.
Without this it would have to call SetDb to reuse Status, writing this
package's shared state from a request path, for a question that does not
depend on any database at all.
The wait was one select over done and ctx.Done(). Both can be ready when
it runs, select picks at random among ready cases, and so a queue that
drained in the same instant the budget expired was reported as an
overrun about half the times it landed there - often enough to be read
as noise, and pointing at the wrong thing when it was not. core's own
RunShutdown re-checks for this reason; this did not.
The tie-break is now a function taking channels rather than a queue,
which is what lets a test hand it a closed done and an expired ctx
together. That state is the whole of the bug and cannot be arrived at
reliably from the outside; over 1000 iterations the single-select
version fails, and the second look does not.
The test for giving up on the deadline read the call counter straight
after shutdownQueue returned, while Shutdown runs on a goroutine nobody
joins. It passed because the goroutine is scheduled promptly, not
because anything ordered the two. The fake now signals that Shutdown has
been entered and the test waits for it.
Both raised by Copilot on #918.
The first attempt at the tie-break test was wrong and is not what
landed: it asserted that an immediately-returning Shutdown always counts
as drained under an already-expired context, which is not true and
should not be - if the goroutine has not run, nothing has drained. That
test failed, correctly. What is being claimed is narrower: when both are
ready, done wins.
Nothing stopped the queue when the process exited. core v2.7.0 made the
drain work - Memory.Shutdown closes the queue and waits for every
consumer to finish what it holds, and the legacy adapter cancels its
context and closes the underlying queue - but no call site ever reached
it. The only Shutdown() in this repository applies to the previous
adapter during a reload, so the installed one was simply left. The login
log, the operation log and the API sync all publish through it, so a
rolling restart dropped whatever had not been consumed, on the path
where the process exits 0 and reports "Server exiting".
Setup now registers a BeforeExit callback that shuts down the adapter
this package installed.
Three things it has to get right, each with a test.
It reads `installed` when it runs, not when it registers. A reload
replaces the adapter, and the one from start-up is a queue nobody has
published to since.
It never goes through sdk.Runtime.GetQueueAdapter. That accessor never
returns nil - with no queue section configured it wraps the runtime's
own fallback - so it would look like it worked while closing a queue
this package neither built nor started. That is the same trap setupQueue
already had to drop an `if q != nil` for.
It registers once. Setup is re-run on every configuration change, and a
callback per reload would leave the shutdown phase holding a row of
identical entries, each eligible to be named as the one that overran the
budget.
That last one needed a seam. shutdownQueue takes the adapter on its
first run, so the second and third callbacks find nothing and return -
three registrations produce exactly the same observable result as one,
and a test going through the effect passes either way. It did: the
counter-proof for "register on every reload" came back green until the
registration was counted at the seam instead.
The wait is bounded here rather than left to the phase. Shutdown takes
no context, so a consumer that never finishes would hold the process
until SIGKILL; the callback gives up and says what is being lost, which
the phase's generic overrun message cannot.
Ordering falls out of the phase rather than being arranged: callbacks
run in reverse registration order, this one registers during setup and
the job scheduler's registers on AfterListen, so the schedulers stop
before the queue drains. Verified against core v2.7.0 rather than read
off the source.
Closes#911.
The warning said to set application.mode and stopped there. Following
that on a running process does not close anything: buildRouter has one
call site, in run(), and route registration is on no phase and no reload
callback, so a configuration reload moves the mode and leaves the routes
exactly where they were.
The reader is then worse off than before they acted. The mode now says
prod, GenWriteRoutesEnabled agrees, and the endpoints are still served -
so the one thing they could check to confirm the fix reports success
while the exposure is untouched, until something restarts the process.
A test pins the gap rather than the prose: build under dev, move the
mode to prod, and the routes are still in the engine. It fails if
registration ever becomes dynamic, which is the change that would make
the new sentence wrong.
That test degrades differently from the others - making it fail means
rewriting registration, not weakening it - so what was checked instead
is that it cannot go vacuous. Both of its premises are guarded: with the
gate always refusing it reports building under dev without the writing
routes, and with the gate always allowing it reports the predicate still
allowing prod. Neither failure can be mistaken for the assertion passing.
Raised by Copilot on #917.
registeredRoutes set config.ApplicationConfig.Mode and gave it back with
t.Cleanup, which runs at the end of the test rather than at the end of
the helper. Everything the caller did after the call therefore ran under
the mode the helper had been asked about, not one the caller chose.
Nothing was wrong yet: the one caller that reads the mode afterwards
sets it itself, and the two cleanups happen to unwind in an order that
leaves the right value. Both of those are accidents, and neither is
visible at the call site.
A defer inside the helper makes the borrowing end where it starts. The
doc comment said the mode was put back before returning while the code
did not, so that is now true rather than aspirational.
The counter-proof is the reason this has a test of its own: with
t.Cleanup back in place TestRegisteredRoutesRestoresTheModeBeforeReturning
fails and nothing else does, which is what a leak this quiet looks like
when something is actually watching for it.
Raised by Copilot on #917.
The gate in the previous commit is decided by application.mode, and the
shipped configuration says dev. So the deployment most likely to be
serving the writing endpoints is the one that changed nothing, and that
is also the one least likely to go looking for them. A gate whose
default is open needs to say so.
Nothing is said in demo mode. The routes are registered there, but
DemoEvn refuses all three by name, so a warning would describe an
exposure that is not present.
The decision is split from the logging so it can be tested. Three
counter-proofs: warning in demo as well fails mode=demo; a warning that
never fires fails mode=dev, which is what shows the line can be reached
at all; and one that always fires fails every mode but dev.
Three of the code generator's endpoints do not read. /gen/toproject
writes seven Go and Vue source files onto the host, one of them under
the path gen.frontpath names; /gen/apitofile writes a migration;
/gen/todb inserts menus and APIs. All three are GET, and all three are
listed in CasbinExclude - which AuthCheckRole skips - so Enforce never
runs for them. Any account that can log in could call them, on every
deployment.
They are now registered only where application.mode is dev or demo. dev
is the shipped default and is where the generator is meant to be used.
demo keeps them because demo mode already has a better answer than a
404: DemoEvn refuses these three by name and explains itself, which is
what the demo is for. test and prod get nothing, and so does a process
whose mode was never set.
This does not make the endpoints safe where they exist; it stops them
existing where nobody should be calling them. A host left on the shipped
dev is still open, which is why the next commit says so at start-up.
CasbinExclude is left alone on purpose. Taking the three off that list
would make them require a permission no existing deployment has granted,
so every non-admin user would start getting 403 from a tool that worked
yesterday. That is a migration, not a guard, and it belongs with a
release that can carry one.
Four counter-proofs, each red on the test that names the behaviour and
green everywhere else: a gate that always allows fails test/prod/unset
only; a gate that always refuses fails dev/demo and takes
TestEveryRouteDemoModeRefusesStillExists with it; moving a read-only
route inside the gate fails the reading test; and spelling the condition
at the registration site instead of calling the predicate fails the
agreement test, which is what keeps that test from being a tautology.
Two pre-existing deviations: a space before the comma in
sysNoCheckRoleRouter's parameter list, and no newline at end of file.
Separated from the change that follows so its diff is only the change.
The comment at the top of this workflow says documentation-only changes
skip it, because a push to master pushes an image, runs the migrations
and restarts the demo container. The ignore list did not cover
scripts/k8s, so editing a manifest that the deploy never reads bought
the site an outage.
The pattern is scripts/k8s/** rather than scripts/** because
scripts/Dockerfile is a build input - go.yml builds the release image
from it on a tag.
This workflow file stays outside the list on purpose. paths-ignore skips
only when every changed path matches, so a change that edits the deploy
still runs it, which is the point.
The comment on replicas gave one obstacle to raising it, the shared log
volume, which reads as the only one. Someone who moves the log path off
that volume would conclude the way is clear.
The scheduler in app/jobs is the second, and it is the one that does not
announce itself. Its handle on a job lives in sys_job.entry_id, one
column shared by every process, and startup zeroes the whole column
before writing its own ids. A second pod therefore erases the first
pod's, and both pods run the full enabled list. Stopping a job from the
UI then removes an entry from whichever process is asked, by an id that
belongs to another one, and answers 200.
See #915.
DemoEvn decided by HTTP method: GET and OPTIONS through, everything else
refused. Three of the code generator's routes are registered as GET and write
anyway - two emit Go source files onto the server's filesystem, and the third
inserts menus, APIs and casbin rules into the database. They sit in a group
whose own name says it does no role check, and a demo deployment lets anybody
log in. So on the demo host any visitor could write to the machine and to the
database, and the one that writes menus had in fact been used: three generated
SysCasbinRule entries is how this was noticed.
The guard now also looks at the matched route. The method cannot answer the
question - whether a request changes anything is not something the verb reports
truthfully here - so the three are named, as gin route patterns, which is what
Context.FullPath returns and how CasbinExclude already spells them.
Changing them to POST would be the better shape and is not this change. sys_api
records an endpoint by method and path and the casbin policy follows it, so
flipping the verb needs a migration and a policy resync; until both land, every
existing deployment would start answering 403 to a role that could use the
generator the day before.
The read-only half stays reachable: preview, the table tree, and the two
database listings. A demo host that cannot demonstrate the generator is as
broken as one that lets visitors write to it - refusing too much is the same
defect facing the other way, and there is a test for that direction too.
Half of the general hole is closed and the other half is written down. The
closed half is a test beside the route registrations: it builds the generator's
routes, enumerates them, and fails if any entry in the guard has stopped being
a real route, so renaming one turns the list red instead of quietly making it
match nothing. It lives there because common/ may not import app/ - which is
also why the guard cannot check its own list from where it is. The open half is
that no static check can tell a handler that writes from one that reads, so the
next GET that writes has to be added by hand. The comment says that rather than
leaving the impression the class is covered.
application.demomsg was configuration nothing read. The message was hard-coded
in the middleware, and the demo host's configured string happened to be
identical, so the setting looked like it worked and never had. It is read now,
with the old string kept verbatim as the fallback, so a deployment that never
set it is answered exactly as before.
This covers demo mode only. On a deployment that is not a demo those three
routes remain in CasbinExclude and stay reachable by any authenticated user
whatever their role; that is a separate decision and is not touched here.
The budget is one number in config/settings.yml. The deadlines that have to
cover it are in four other files, none of which anybody edits while thinking
about shutdown - so raising the budget passes every test, deploys, and has the
cleanup callbacks killed on the next release.
Two checks share one arithmetic and one five-second margin.
shutdown-budget-overruns-grace compares preStop + drain + server + cleanup
against terminationGracePeriodSeconds in the shipped manifest. Those two files
are not merely adjacent examples: scripts/k8s/prerun.sh builds the
settings-admin ConfigMap out of config/settings.yml and the Deployment mounts
it, so the manifest deploys that file.
docker-stop-cuts-shutdown-short covers the three ways this container is
stopped: `docker stop` in the release workflow, the same in the Makefile, and
stop_grace_period on a compose service that runs this repository's own image. A
service running a database is not this process and is left alone. The duration
is parsed rather than scanned for digits - compose accepts 1m30s, and reading
the first number out of it would call ninety seconds one.
All three spellings of the deadline are read: --timeout, the deprecated --time,
and the short -t. A deadline the check cannot read is reported as no deadline at
all, so recognising only one of them would call a correct command broken and
send whoever fixed it towards the spelling docker is retiring. The message
quotes the flag back in the spelling it was written in, for the same reason:
suggesting a flag the line does not use is how a tool teaches people to
disbelieve it.
What neither covers is `docker rm -f`, which has no deadline to compare
against: it is SIGKILL by definition. That gap is deliberate, and it is why the
previous commit changed the one place that used it on a container that might
still be running.
Both report at two levels. A budget that already overruns is an ERROR; one that
fits with nothing to spare is a WARN, because it works today and failing the
build on a working configuration is how a project teaches people to ignore its
warnings. The two are exclusive: an overrun satisfies the headroom condition as
well, and an ERROR that always drags a duplicate WARN behind it teaches the same
lesson.
preStop is in the sum although the shipped manifest has no hook. That is the
point - a hook added later is spent before the process is told anything, and a
self-check that could not see it would understate the real budget by however
long somebody set it to, which is worse than not checking. A hook whose duration
cannot be read is reported rather than counted as zero.
The fallbacks for fields the settings file leaves out are read from the
constants in the scanned tree, not copied here; if they are renamed the run
stops instead of going quiet with the wrong numbers.
The wording differs by audience on purpose. At run time this is somebody else's
deployment under constraints the process cannot see, so the log states a
minimum. These checks read files this repository owns, where there is standing
to ask for headroom, so they name a target.
The table in AGENTS.md is relisted while it is being touched: the two new
checks, plus datascope-route-unguarded, which has been missing since it was
added. The hard-coded count is gone - it said seven and there were ten, which is
what a written-down count does. AGENTS.md and docs/contract.md both sent readers
to `go run ./tools/checksilent -h` for the list of checks; that prints
command-line flags and has never printed a check, so both now point at
runChecks.
The yaml parser moves from an indirect requirement to a direct one - it was
already in the module graph - and tidy drops four go.sum lines left over from
two older releases of core.
Stopping this process takes drain + server + cleanup seconds: eight out of the
box, and more for anyone who configures a drain window. Three places decide
whether it gets that long, and none of them was written with it in mind.
The release workflow stopped the previous container with the default deadline,
which docker sets at ten seconds. The compose file - which the Makefile calls
the first way to run this - set no stop_grace_period, so it took the same ten.
Under either, a drain window over two seconds would have been cut off by
SIGKILL part-way through the cleanup callbacks: this project's own deployments
could not have run the capability it ships.
The third was worse. `make run` removed the previous container with `docker rm
-f`, and the force flag kills a running container outright - "uses SIGKILL", in
docker's own words - with no grace at all. Restarting locally cut every
shutdown short, so the drain window would never once have been reached on a
developer's machine. It now stops with a deadline and then removes, which
leaves what gets removed unchanged: on a container that has already stopped,
stop is a no-op.
So: --timeout 30 in the workflow, stop_grace_period: 30s on the compose
service, and stop --timeout 30 before the removal in the Makefile. --timeout
rather than --time, which docker still honours but has deprecated - it prints a
warning on every use, and a deploy log that always carries a warning is one
nobody reads.
The three remaining `docker rm -f` calls in the workflow are left alone. Two
remove containers that have already been stopped and one is the rollback path,
and nothing static can tell those apart from a container that is still running -
which is also why the check added next does not look at `rm -f` at all: a forced
removal has no deadline to compare against. What keeps that path honest is the
line above it, not a check.
Thirty will drift the first time somebody raises a budget. The next commit is
what notices, which is also why these comments name a check that does not exist
yet.
The manifest in this repository had no probes at all. A pod was sent traffic as
soon as its container was running, whether or not the database it needs was
reachable, and it was stopped with whatever grace period Kubernetes defaults to
rather than one chosen against what this process actually spends shutting down.
It now mounts both probes, at the endpoint that answers each question:
readiness at /ready, which fails while a dependency is unreachable, and
liveness at /health, which is a bare 200 because restarting a process whose
database is down turns one outage into a crash loop. Both skip the rate
limiter, which is why that had to land first.
timeoutSeconds is 3, not the default 1. The handler allows its checks two
seconds, so at the default a database answering in 1.2s would be recorded as a
failed check while the handler was returning 200 - the probe would be failing on
the orchestrator's stopwatch, not on its own. The comment beside that constant
said the constraint was the polling period; the constraint is the per-check
timeout, and it is now written down correctly.
terminationGracePeriodSeconds is 30, against a shipped budget of 0 + 5 + 3.
Raising drain means raising this too, in the same commit; the check that
notices when somebody does not arrives two commits from here.
replicas stays at 1, and the comment says why that makes the drain window worth
nothing: there is nowhere to send the traffic this pod stops taking. Raising it
needs one more change than the number - the volume is shared by every replica
and the log path lives on it, so a second pod would append to the same rotating
file. The reason not to raise it is not the one the review assumed: the claim
was that the PVC is ReadWriteOnce, and it is not, it is ReadWriteMany on nfs-csi.
There is no preStop hook. How long one should sleep depends on how fast the
thing in front removes this instance, which the repository cannot know, and a
manifest carrying both a preStop sleep and a drain window is the double-counting
trap - the budget would be spent twice and the start-up line would report half
of it.
The three budgets are spent one after the other, so what has to fit inside the
orchestrator's grace period is their sum - and nothing said what that sum was.
Working it out meant reading a configuration file, remembering which fields
were absent, and knowing what each one falls back to.
Start-up now prints it: the three values and the total, taken from the resolved
budget rather than from the file. A field left out still costs its default, so
adding up what was written down understates the total by exactly the fields
nobody wrote - which is the arithmetic somebody doing this by hand gets wrong.
Whether the total fits is a separate question, and the framework cannot answer
it alone: `docker stop` allows ten seconds and Kubernetes thirty, three times
apart. A fixed threshold would have warned about the manifest this repository
is about to ship. So extend.shutdown.grace is optional, nothing reads it during
a shutdown, and when it is absent the line says so and prints both reference
values instead of judging.
When it is set and the budget does not fit, the warning names the shortfall:
how many more seconds are needed. A minimum, not a target - this is somebody
else's deployment under constraints this process cannot see, and asking them to
leave headroom on top is not this line's business. Equal does not fit either;
the grace period is when SIGKILL is sent, so a budget that ends exactly then
leaves the last callback no time to return.
/ready has failed from the moment shutdown begins since the readiness probe was
added, and the order it does that in is right: reversed, the state would be
reported after the connections were already cut. But order alone does not
produce a window. Nothing waited between the flip and Shutdown, so the two were
microseconds apart, and a poller on a multi-second interval never saw the 503 -
it saw a refused connection, which is the thing the probe was supposed to
avoid. Polling a container through a SIGTERM on the demo host recorded exactly
that: 200, then connection refused, and no 503 in between.
extend.shutdown.drain is that wait. The process keeps serving normally for it -
answering requests, not refusing them, because refusing them would move the
outage earlier rather than avoid it - and only then closes the listener.
It is zero by default, so nothing changes for a deployment that does not ask
for it. That is not timidity: the budgets are spent one after another, and a
non-zero default would push every existing shutdown closer to the orchestrator's
grace period, where being cut off part-way through the cleanup callbacks is
worse than never draining at all.
Keep-alive is switched off with the flip. The server keeps connections alive
until Shutdown sets shuttingDown() itself, so without this the pooled
connections a balancer holds would sit untouched for the whole window and be
cut at the end of it anyway - the cost of the window without its benefit. This
is the switch Shutdown flips, moved earlier by the window's length.
The signal disposition is restored after the window rather than on the first
signal. Before there was a window, the interval where a second signal killed
the process outright was only reachable while a cleanup callback hung; putting
a multi-second wait inside it would have made every ordinary shutdown
interruptible for the length of the drain. A second signal during the window is
taken by the channel and ends the window early instead - somebody sending
another kill wants this over with sooner - and the escape hatch comes back the
moment the window does.
What the window is worth depends on who removes this instance. A balancer that
polls /ready acts on the 503 and needs the window to cover its check interval
times its failure threshold; a Kubernetes Service withdraws the endpoint when
the Pod is deleted, concurrently with SIGTERM and regardless of what the probe
returns, and there the window covers the delay in that removal reaching every
node. The three comments that used to say a balancer "has a chance to" take the
instance out said it without either qualification, which is how a claim comes to
be repeated after a live test has refuted it.
The subprocess test polls the real probes on a connection it opens after the
signal - a reused one can be served after the listener is closed, which would
let this pass against a shutdown that had already broken it - and asserts on the
draining answer in the body, not on the status code. With no database the status
is 503 from start-up, so a status-code assertion would hold even with
BeginDraining deleted. Two window lengths, because one proves only that
something takes that long.
The limiter is installed on the engine and the probes are routes like any
other, so above the threshold they are answered with 429 too. Point a liveness
probe at one and the failure mode writes itself: traffic crosses the threshold,
the probe collects three 429s, the kubelet restarts the container, the capacity
that was already short gets shorter, and the instances that are left are pushed
further past the threshold. The limiter working exactly as designed is what
kills the pod.
It is the argument common/health already makes about restarting a process whose
database is unreachable, applied to load: turning one outage into a crash loop
is not an improvement on the outage.
Nothing points a liveness probe at these routes yet. The manifest that will is
two commits away, and this has to land first, because that manifest without
this change would be actively harmful.
The exemption wraps the middleware rather than teaching the limiter about these
paths. common/ may not import app/ - the contract check enforces it - so the
limiter cannot name routes that are registered over there. Wrapping it in the
command package, which imports both, is what keeps the boundary.
Naming those routes needs them exported, so the group prefix and the two paths
become constants and the router function becomes RegisterMonitorRouter. That
also gives a test something real to mount: a probe asserted against a
re-implementation of itself is a test of the copy.
The check that the middleware never runs is separate from the check that the
answer is not 429, because a probe can produce a 429 on its own. What has to be
true is that the request never reached the limiter.
How long a shutdown may spend waiting for in-flight requests, and how long the
cleanup callbacks get after that, were compile-time constants. The two together
have to fit inside whatever grace period the orchestrator allows before it
sends SIGKILL, and that number is not the same everywhere - `docker stop`
allows ten seconds, Kubernetes thirty by default - so the one deployment shape
these constants suited was the one they were written for.
They now come from extend.shutdown, beside rateLimit. Not from application:
that section is a fixed struct in core, and the decoder discards keys it has no
field for without an error, so a budget written there would be accepted and
never applied. That is the failure this whole change is about, and putting the
configuration where it cannot be read would have reproduced it.
Both fields are pointers, following RateLimit.InboundQPS: nil means "not
configured" and takes the default, and a number that was written down is spent
literally, zero included. Without that separation `server: 0` - do not wait for
in-flight requests at all, which is a reasonable thing to ask when the grace
period is very short - could not be expressed, and the section would need a
paragraph explaining which zeros mean what.
A negative is refused rather than clamped. Correcting a value quietly is the
same failure in a different costume, and Budget returns the error instead of
ending the process so that the rule can be tested without a subprocess.
The defaults live in config as seconds and in cmd/api as durations, both from
the same constants, and a test asserts the two agree - a deployment that
configures nothing is entitled to one answer about what it spends, not two.
The last test loads the two settings files this repository ships through the
real loader and asserts the section arrives with the documented values. Nothing
weaker can tell "the key is read" from "the key is discarded": the struct
compiles either way.
The child process built a server, restored its own signal disposition and
called shutdownServer and runShutdownHooks itself, in an order it chose. It
never called anything run() calls. So the assertions were about a copy of the
sequence: move a step in the real one, or drop it, and every test here stays
green. The acceptance criteria these back are worth exactly as much as that.
The child now calls gracefulShutdown and asserts on what comes out of it. The
budget it spends is defaultBudget with one field shortened where a test needs a
deterministic timeout, which is also how the two waits stop being wired by
hand.
The stuck-shutdown case changes shape as a result. It used to sleep inside the
child, between the steps it had copied; there is no "between" to sleep in any
more, so it registers a BeforeExit callback that never returns and gives it a
budget long enough to hang on. That is where a shutdown actually hangs, and it
now runs through the same function - which means this test also pins where the
signal disposition is restored, rather than just asserting that the child dies.
It signals repeatedly rather than once. The marker is printed immediately
before gracefulShutdown is entered, so a single signal sent on seeing it can
still arrive before the disposition is restored, land in the buffered channel
and be dropped. Which signal does the killing is not the assertion; that one of
them can is.
The steps between the stop signal and the last log line were written inline in
run(), which left nothing for a test to call. The signal tests reproduce that
sequence instead: they build their own server, restore their own disposition,
and call shutdownServer and runShutdownHooks in an order of their own. So they
assert against a copy - reorder the real sequence, or drop a step from it, and
they stay green.
The sequence now lives in gracefulShutdown, and the waits it spends are a
budget rather than two constants read at the point of use. Nothing changes
about what happens or in what order: the same disposition is restored first,
the same two announcements are made, the same waits are spent, and run() logs
the same two errors with the same messages.
Returning those errors instead of logging them inside is what lets a caller
other than run() react to them. That matters for the next commit, where the
tests stop reproducing this sequence and start running it.
Three comments said readiness failing before the server stops accepting gives
a load balancer the chance to withdraw the instance before its connections are
cut. Nothing between the two lines makes that possible: BeginDraining is
immediately followed by the shutdown, and a poller on a multi-second interval
never observes the flip.
On Kubernetes the endpoint is withdrawn when the Pod receives a
deletionTimestamp, concurrently with SIGTERM and independent of what the probe
returns, so the probe result is not the mechanism there either.
The order itself stands - reporting the state after the connections are cut is
worse - so the comments now say the order is necessary and not sufficient, and
that a window needs a configured delay that does not exist yet.
Only ErrQueueClosed was examined and every other error was discarded, so a
run where nothing reached a queue at all would leave the refusal count at
zero and the test green. The first unexpected error is now kept and fails
the test.
The pool is sized so a full queue cannot be one of them: it returns an error
of its own and is expected while the consumer is held, which would otherwise
make the new check fire on the normal path.
Two fixed sleeps decided when this test looked: one to let the consumer pick
a message up, one to let publishes accumulate inside the reload. Both are
guesses about how fast the runner is. The consumer now signals on its first
delivery, and the measurement waits until enough publishes have landed.
The "nothing was published" guard goes with them. It was the weaker form of
the same check, and it ran after the fact instead of holding the window open
until there was something to measure.
The assertion demanded zero refusals during a reload, and this ordering
cannot deliver that. GetQueuePrefix returns a wrapper that captured the
adapter, so a producer that fetched before the swap and appends after
Shutdown has begun is still holding the old queue. That window is one call
wide; closing it means resolving the adapter inside Append, which is core's
to change.
What the ordering removes is the sustained window - every producer that
fetches during the wait. Measured on a race-enabled run: 174 of 174 publishes
refused with the old order, 1 of 174 with the new one. The old assertion
therefore failed about half the time on a change that works.
The publishing goroutine was told to stop and never waited for. t.Cleanup
restores sdk.Runtime while a producer that has not yet noticed the stop is
still reading it, which -race reports as a write and a read on the same
package variable. Signalling is not joining.
Shutdown now waits for its consumers to deliver what the queue still holds, and
setupQueue called it first. For that whole wait sdk.Runtime still pointed at the
adapter that had stopped accepting, so every Append landing in the window came
back ErrQueueClosed - and both call sites in common/middleware log that at error
level while the row never reaches the database.
Measured with a held consumer: 177 of 178 publishes during one reload.
Installing first leaves no window. A producer fetches the adapter per call and
gets either the new queue or the old one, and both accept; the old one still
drains, because Shutdown is what waits for that.
The difference only exists during the wait - after Setup returns the two orders
look identical, which is why the test holds a consumer and publishes throughout
the reload rather than checking the state afterwards.
The counter-proof compiles and reports the 177.
It carries the queue shutdown fixes: a closed queue now delivers what it already
accepted and stops the goroutines consuming it. Both matter here, because this
host rebuilds its queue adapter on every configuration reload and shuts one down
on the way out.
Nothing in this commit uses the new behaviour. The one place that has to change
because of it follows.
One fixed key meant two probes overlapping - two /ready requests, or two
instances against the one redis, which is the normal deployment - overwrote each
other's value between the write and the read, and each concluded the cache was
broken. A readiness probe that reports false negatives under load pulls healthy
instances out of the pool, which is worse than not probing.
The key now carries eight random bytes. The written value is still read back,
because that is what tells a healthy cache apart from one that answers "miss"
for everything, and the key is deleted afterwards on a best-effort basis - its
error is dropped deliberately, since the verdict is already decided and a cache
that cannot delete what it just wrote is not a reason to refuse traffic.
The first version of the concurrency test had no teeth: the probes are short
enough that the scheduler ran them one after another, so the fixed-key
counter-proof passed three times out of three. The fake cache now holds every
writer until all of them have written, which makes the interleaving the test is
about actually happen. With one key that is a deterministic 15 failures out of
16 - only the last writer's value survives - and with a key per probe, none.
/health returned 200 without asking anything. Whatever it was meant to say, an
orchestrator reading it learned only that a process was accepting connections.
The two questions are not the same one, and the answers differ:
- /health stays a bare 200. It answers "should I restart you", and a process
whose database is unreachable does not want restarting - that turns one
outage into a crash loop and discards the connection pool, the cache and
every request in flight on the way.
- /ready is new. It answers "should I send you requests", fails while a
dependency is unreachable, and fails from the moment shutdown begins.
That last part is what the life-cycle phases bought. BeginDraining sits next to
BeginShutdown, before the server stops accepting, so a load balancer is told to
stop sending while this instance can still finish what it holds. Reversed - and
that is where it was - the connections are cut first and the probe reports it
afterwards.
The queue is deliberately not checked. Nothing on AdapterQueue answers "are you
reachable" without publishing something, the memory backend cannot fail, and a
queue that is down degrades logging rather than stopping requests: a reason to
alert, not a reason to leave the pool.
The cache probe writes and reads back rather than only reading. A cache that
answers "miss" for every key - a client pointed at the wrong server - is
indistinguishable from a healthy one on a read alone.
Every check runs behind a recover, and that is not defensive habit. The test for
"nothing configured" found the reason: GetCacheAdapter builds a wrapper around
whatever is configured and returns it even when nothing is, so the value is not
nil, the cache inside it is, and Set dereferences it. A nil check cannot see
that, and GetQueueAdapter behaves the same way. Whatever the cause, a probe is
the last thing that should be able to take the process down - the caller is
asking whether this instance is well, and killing it is the wrong reply.
The counter-proof compiles and fails: without the recover, the unconfigured case
panics rather than reporting two failed checks.
Setup installs the cache and queue adapters on sdk.Runtime, which is a
package-level singleton, and records what it installed in this package's own
variables. The test left all of it behind, so what a later test in this binary
saw depended on whether this one had run - the leak cmd/api's freshRuntime and
common/middleware's copy of it exist to prevent.
sdk.Runtime is swapped for a fresh one and everything is put back in Cleanup.
Issue #892 is that a reload replaces the queue adapter and the consumers
registered against the previous one are left attached to a queue nobody
publishes to any more.
The fix has two halves and only one of them was covered. attachQueueConsumers
gives a new queue its own consumers and the same queue none, which cmd/api
tests against a queue it controls by passing generation numbers in by hand. What
nothing asserted is that a reload actually produces a new generation for it to
notice - the half that lives in this package.
Setup is what config re-runs on every change, so calling it twice is what a
reload does here. The generation goes 0, 1, 2.
The counter-proof compiles and fails: dropping the increment in setupQueue
reports that the first Setup installed no queue at all, because a generation
that never moves is indistinguishable from never having been set.
This closes the loop rather than adding coverage for its own sake: with both
halves asserted, the claim that #892 is fixed rests on tests instead of on
reading the two functions and believing they meet.
AfterListen promises a hook that the port answers. The bind was moved onto the
caller's goroutine to keep that promise, but with ssl enabled there was a second
way to fail after the announcement: ServeTLS reads the certificate files itself,
on the serving goroutine, so a bad path or an unreadable key surfaced once the
hooks had already run.
tls.LoadX509KeyPair now runs before anything is announced, and its error is
returned from startServing the way a failed bind is. ServeTLS still does the
real work - handing it a tls.Listener built here instead would take over the
HTTP/2 negotiation it sets up, and quietly drop h2 for every TLS deployment. The
cost is one extra read of the certificate at startup.
The fatal in the serving goroutine said "listen:". Neither the bind nor the
certificate reaches it any more, so it says "serve:".
The test covers the certificate path alongside the bind: neither may announce
the phase, and neither may seal it.
The counter-proof is not clean, and saying so is the point. Removing the check
does turn the run red, but through log.Fatal killing the process from the
serving goroutine - "fatal serve: open no-such.pem: no such file or directory" -
rather than through the assertion. That still demonstrates the defect, because
the process could only get there after startServing had returned successfully
and the phase had been announced; it cannot be observed from inside the test,
because the fatal races the assertion that would report it.
Also: the redis-backed queue tests now fail instead of skipping when CI is set
and GO_ADMIN_TEST_REDIS_ADDR is not. A workflow that renamed the variable or
dropped the service would otherwise stay green while those two tests quietly did
nothing - the same shape as the defect they exist to cover. Locally, with no CI
in the environment, they still skip.
buildRouter is split out of run() so the order it establishes can be asserted:
the phase is announced, then initRouter builds the engine, then runStartupHooks
drains the registries.
The test covers both halves of the distinction the contract draws. A
BeforeRouter callback sees no engine - that is what the phase means, the last
point at which a module can still affect how routes are built. A callback in the
before registry, two lines later, sees one. The names invite treating them as
the same moment and they are not.
No database is involved. AuthInit reads ApplicationConfig.Mode and JwtConfig and
nothing else, and building a router registers handlers rather than calling them,
so the whole sequence runs in a package test with two package-level values set.
freshRuntime swaps the global runtime for the duration: runStartupHooks seals
the registries it drains, and a sealed registry silently drops everything
registered afterwards, which would leave every later test in this binary passing
while proving nothing.
The counter-proof compiles and fails - announcing the phase after initRouter
reports "BeforeRouter saw engine &{...}, want nil".
The rule that consumers are registered before the queue is started had no test
that could fail on the backend it exists for. Everything so far ran on the
memory queue, which is the default: queue.Memory's Register starts another
consumer goroutine whatever the state, so the wrong order passes there. A suite
that only exercises the default reports success for a queue that accepts no
consumers at all.
CI gets a redis service, and two tests build the queue the way setupQueue does -
through config.QueueConfig.Setup, so what is under test is the adapter this
repository actually gets, LegacyQueueAdapter included. They skip without
GO_ADMIN_TEST_REDIS_ADDR, so a developer with no server still gets a green run.
Registering first and starting second delivers the message. Starting first and
registering second is refused: no consumer group was created, so Append comes
back with storage.ErrNoHandler. Pinning that particular error rather than "some
error" is deliberate - the test is about the missing consumer, and a connection
failure that happened to error too would otherwise pass for it.
Running it corrected something written two commits ago. The claim there was
that a late registration loses consumers "with nothing said". Only half of that
holds: the registration is silent, because Register returns nothing, but every
publish afterwards fails loudly - ErrNoHandler, logged at error level by both
call sites in common/middleware - while the log rows are never written. The
symptom is missing rows plus a lot of noise, not a quiet nothing. That commit's
message and the contract doc both say so now.
core's contract says what the four phases promise. This says which line of
cmd/api/server.go each of them is, which is the part an application author
cannot read out of core.
Three things are recorded because getting them wrong is silent:
- BeforeRouter is not the before registry. Those callbacks run from
runStartupHooks, which is after initRouter has built the engine; the phase
is before it. The two are one line apart in the same function and describing
them as equivalent is the mistake this paragraph exists to prevent.
- AfterResource runs again after every configuration reload, so a callback
there is idempotent with respect to a resource rather than doing nothing
the second time. The queue consumers are the worked example, in both
directions: a new adapter must get consumers, the same adapter must not get
them twice. Identity has to come from where the resource is created -
GetQueueAdapter and GetQueuePrefix build a fresh wrapper per call, so two
of them never compare equal however often the adapter underneath changed.
- Consumers must be registered before the queue is started, and which
implementation is behind the interface decides whether that matters:
QueueConfig.Setup hands back queue.NewMemory when there is no redis
section, and that one does not care; a redis section reaches
LegacyQueueAdapter, whose Register cannot report a refusal. The table says
so rather than leaving "only on redis" as a claim. What is silent is the
registration alone - every publish afterwards is refused with ErrNoHandler
and logged at error level, so the symptom is missing log rows plus a lot of
noise, not a quiet nothing.
The third-layer table loses its "queue consumers are lost after a hot reload"
row, which is what AfterResource is for, and gains the honest replacement: the
four phases are the only mount points there are. There is no "after the routes
are installed, before the socket is listening".
AfterListen is described as the port being bound rather than Serve being in its
accept loop. Serve runs on another goroutine and may not have reached the first
Accept; what is true is that the bind returned, so the kernel is queueing
connections. A bind that fails produces no phase at all - the error returns
from run() and the banner never prints.
The per-tenant setup ended with `defer crontab.Stop()` on the line above
`select {}`. The select never returned, so the deferred call was unreachable
for the life of the process: the scheduler had never once been stopped. And
because setup never returned, the `for k, db := range dbs` loop in Setup never
reached its second iteration - with several tenant databases configured, only
whichever one came first out of the map ever got a scheduler at all.
Both fall out of deleting the select, which was blocking for nothing: cron.Start
is `go c.run()` and has never needed anything to hold the caller.
The stop becomes a BeforeExit callback. cron.Stop returns a context that closes
once the jobs already running have finished, so the shutdown budget has
something real to bound - and giving up on that wait leaves those jobs running
until the process exits, which is better than holding the whole shutdown open
for one job that will not end.
Startup moves from a bare goroutine in run() onto AfterListen. Two reasons: the
phase runs behind core's panic guard, which does not reach across a goroutine
boundary, so a panic while loading jobs used to take the process down; and the
jobs it starts can call the API, which is only true once the socket is
accepting. It can be synchronous now precisely because setup returns.
Tested where it can be: startCrontab is split out so a scheduler can be started
with no database in sight. The job runs every second; after RunShutdown, two
and a half seconds of silence is the assertion. The counter-proof - registering
no callback, which is what this commit replaces - compiles and reports "the job
fired 2 more times after shutdown".
There is one test, not several, because BeforeExit closes to further
registration once it has run; a second RunShutdown in the same binary would
find an empty registry and pass while proving nothing.
**The multi-tenant half has no test.** setup needs a *gorm.DB per tenant before
it reaches the line that was blocking, and this repository's CI has no database
- `make build` is CGO_ENABLED=0 with no sqlite tag. It is the same defect
though: the loop could not advance past a call that never returned.
setupQueue ended with `go queueAdapter.Run()`, and the three log consumers were
registered afterwards, from setup(). The contract implementations refuse a
registration once the queue is running - memqueue and the redis queue both
answer storage.ErrQueueAlreadyStarted - and Register cannot report it: it
returns nothing, which its own comment in core records as the reason the
interface is deprecated. Start first and register second, across two
goroutines, and the registration is dropped without the caller being able to
tell.
What follows is not quiet. No consumer group was created, so redis refuses
every later publish with storage.ErrNoHandler, and go-admin logs that at error
level from both call sites while the login and operation log rows are simply
never written. The silence is in the registration; the cost shows up on every
request after it.
Which implementation is behind the interface depends on the configuration.
config.QueueConfig.Setup returns queue.NewMemory directly when there is no
redis section - and that one does not care about the order, because its
Register just starts another consumer goroutine. Only a redis section reaches
storage.LegacyQueueAdapter, which wraps the contract implementation and
therefore refuses. So the defect is invisible in the default deployment and
shows up only where redis is configured, dropping the login log, the operation
log and the api check - the three things #892 was about.
The start therefore moves to the code that registers, and nothing starts the
queue but that.
The registration also moves onto AfterResource. It has to: a reload rebuilds
the adapter, and consumers attached to the one that existed at start-up are
attached to a queue nobody publishes to any more. Being on that phase means
running again on every reload, so the callback is idempotent with respect to a
given queue rather than "does nothing the second time" - registering twice on
the same queue would give every message two consumers and write every log row
twice.
Identity for that comes from common/storage, where the adapter is built, as a
generation counter. It cannot come from the accessors: GetQueueAdapter and
GetQueuePrefix build a fresh runtime.Queue wrapper on every call, so comparing
two of them compares two wrappers and never matches however many times the
adapter underneath has been replaced. A counter also keeps the comparison on a
uint64 rather than an `==` between two interface values, which would panic on
an adapter type that is not comparable.
Generation 0 means the configuration has no queue section, so nothing was
installed and the runtime hands back its own memory queue. That case still gets
consumers, because the registration this replaces was unconditional and
dropping it would stop the logs for anyone who commented the section out.
Two things fixed on the way past:
- `if q := sdk.Runtime.GetQueueAdapter(); q != nil { q.Shutdown() }` was
always true. GetQueueAdapter never returns nil - with nothing configured
the runtime falls back to its own memory queue and wraps that - so the
first start shut down the fallback queue before anything had used it. Only
an adapter this package installed is shut down now.
- config.Setup becomes bootstrap.SetupConfig, which is what announces
AfterResource, and announces it after the callbacks that build the
resources rather than before.
attachConsumersOnce is split out so the order and the once-ness can be checked
against a queue the test controls; neither can be read back out of a real
adapter. Four tests cover the ordering, both directions of the idempotency
rule, and the unconfigured case. Both counter-proofs compile and fail: calling
Run before the registrations reports each of the three as "came after Run", and
dropping the generation guard reports eight calls where four are wanted.
One honest limit: the counter-proof for the ordering makes Run synchronous.
The original arrangement started the queue on another goroutine, and a race
cannot be made to fail every time - which is the reason the order is enforced
by structure here instead of being left to be noticed in use.
A module can now register cleanup and have it happen. Until this commit the
process stopped serving and returned; anything a module had set up went down
with the process rather than being taken down.
BeginShutdown is said first, before anything is dismantled. Without it a
configuration reload arriving in this window re-runs AfterResource - rebuilding
the pool and the queue adapter and re-registering consumers - on top of cleanup
that has already run.
The cleanup runs whether or not Shutdown reported an error, which is the whole
reason that error stopped being fatal in the first place: Shutdown fails exactly
when connections were still in flight, and that is when there is most left to
take down.
The two budgets are spent one after the other, so what has to fit inside the
orchestrator's grace period is their sum. `docker stop` allows 10s by default
before SIGKILL; 5+3 leaves room to finish returning. Raising one without
lowering the other buys nothing.
Both halves are tested through the existing subprocess child, which now
registers a BeforeExit callback of its own:
- after a Shutdown that timed out, the callback still runs. Moving the call
into the success branch reports "the BeforeExit callback did not run after
a failed Shutdown".
- a callback that outlasts its budget is abandoned, not awaited. It sleeps
two seconds against a 300ms budget; RunShutdown reports the deadline, the
process exits cleanly inside one second, and the callback's own marker
never appears. Widening the budget to five seconds makes the test time out
waiting for the exit, which is what "awaited" looks like.
Both counter-proofs compile and fail.
zhangwenjian