analyzers, cache: Allow to shut down gracefully #392

mitjat · 2023-04-27T19:46:20Z

This PR was motivated by #360 which introduces an on-disk cache (KV store), but does not close it cleanly when exiting. This PR adds a cleanup mechanism to the cache, and (partly by necessity, partly for code hygiene) extends the cleanup mechanism to all the analyzers.

At a high level, all analyzers are now provided with an external context.Context in their Start() method, and they are on the lookout for the ctx.Done() channel closing. The top-level code closes the channel on regular program termination and on SIGINT (Ctrl+C).

There is an additional change piggybacking on this PR:

The recently-added KVStore (cache) now uses cbor to serialize its keys. It previously used gob, which in my testing complained for certain keys. (I think null pointers? I didn't investigate further, as I think it's preferable to not introduce new serialization formats (here, gob) into the project anyway.)

Testing: Ran in three different scenarios, verified that KV store (which is the furthest down the stack of cleanup methods) closes correctly:

analyzers with a limited range in config; allow them to finish "on their own"
kill analyzers with a single ctrl+C
kill analyzers with a double ctrl+C (by introducing an artificial delay into cleanup); verify that the program is killable at the cost of incomplete cleanup

storage/oasis/nodeapi/file/consensus.go

cmd/analyzer/analyzer.go

pro-wh · 2023-04-27T20:08:18Z

cmd/analyzer/analyzer.go

+		select {
+		case <-signalChan:
+			// We received the first Ctrl+C; try to shut down gracefully.
+			a.Shutdown()


the caller of Start, either runAnalyzer or func in rootMain calls .Shutdown. should only have to return, rather than putting these a.Shutdown calls in various places. are we able to return?

oh are we not able to return because we don't cancel the context until something calls Shutdown thus calling cancelAnalyzers? seems like it would be more natural to receive the signal and only call cancelAnalyzers. no a.Shutdown(). and let us return normally

that might also let us extract this into a helper that only creates a ctx that cancels on ctrl+c

I don't fully understand this comment. Is your main concern that the caller of Start() now needs to be careful to call Shutdown(), therefore a clean shutdown is not guaranteed? Not sure what kind of returning you had in mind; where and why would the callers want to return?

This might be relevant: The analysis Service (which owns/controls all the analyzers; the other service we have is the API service) was originally designed with explicit cleanup, i.e. with Start+Shutdown. So the Service's Shutdown() is always called when appropriate, e.g. here (and in another spot; there are only two calls to Start() anyway).

yup, referring to that. i.e. it's (or was previously at least) up to the thing using the analyzer Service (1) to call its Start and (2) to call its Shutdown.

my understanding of this change is that Shutdown is now something that sometimes gets called by the service itself inside Start, sometimes from outside. in fact, if I'm following this right, both?

I feel it's a smaller change and less complicated to cancel the context and let the subordinate analyzers finish, let the Start return, and let the thing using the analyzer Service call Shutdown as before

Shutdown is now something that sometimes gets called by the service itself inside Start, sometimes from outside

That was indeed funky. Thank you for noticing.

Your observation caused me to think about the code more, and I noticed more smells that I then refactored away:

The Shutdown() method of the Service had to be called by the caller of Service::Start(). Then it makes more sense to just call defer Shutdown() from Start() and not burden the caller. We do so now.

The code introduced by this PR repeated that sin (Start+Shutdown) at the Analyzer level. I changed it now to also use defer.

Several Shutdown() methods throughout the codebase were IMO misleadingly named. They did not actively cause anything to shut down; they performed resource cleanup and assumed that any active processing had completed. I renamed them appropriately, IIRC to either cleanup() or Close().

I also refactored the code around this comment thread so it no longer waits for ctrl+C in a separate goroutine; I find the new approach much easier to grok.

I added all these changes as a separate commit, should you prefer to view them that way, but I think it makes more sense to diff against main.

oo looking good

little asymmetry, but don't let this distract you: initializing those resources is in a public function NewMain etc, while cleaning them up is in a private method cleanup. once you make a service, you have no way out other than to Start it and let Start clean things up when it's done

cmd/analyzer/analyzer.go

ptrus · 2023-04-30T08:26:30Z

analyzer/runtime/runtime.go

-func (m *Main) Start() {
-	ctx := context.Background()
+func (m *Main) Start(ctx context.Context) {
+	defer m.cleanup()

 	if err := m.prework(); err != nil {


Also pass the ctx into prework so that this cancelable context is also used in SendBatch there.

thanks, are there any other context.Background's around?

analyzer/evmtokenbalances/evm_token_balances.go

pro-wh · 2023-05-01T20:46:25Z

analyzer/runtime/runtime.go

@@ -143,6 +149,14 @@ func (m *Main) Start() {
 			m.cfg.Range.From, m.cfg.Range.To))
 }

+func (m *Main) cleanup() {
+	if err := m.cfg.Source.Close(); err != nil {
+		m.logger.Error("failed to cleanly close consensus data source",


consensus -> runtime (I think?)

cmd/analyzer/analyzer.go

pro-wh · 2023-05-01T21:19:55Z

cmd/analyzer/analyzer.go

+			a.logger.Info("all analyzers have exited cleanly")
+			return
+		case <-signalChan:
+			a.logger.Info("received second interrupt, forcing exit")


analysis of this logic:

which is a little sophisticated. do we specifically want to program a custom second-ctrl-c behavior? if not, we could unregister the handler and let the second ctrl+c do whatever the default action is. exit the program immediately

I like it! Implemented it now. For my taste, the code is about the same complexity to understand though. There's no more explicit handling of a second ctrl+C, which is nicer and simpler (and more agnostic of surrounding code, which might theoretically have its own handlers); that's good. But there is the additional cognitive burden of tracking whether the custom signal interceptor is active or not.

I also feel the image is harder to grok than the code :). Also, not sure it's correct; the far left path takes three ctrl+C to reach "process exited"?

right, in the previous code, the second ctrl+c makes this function return, which transfers control to the defers. first, the defer to unregister the signal notifier. second, to call cleanup. cleanup I'm pretty sure is fast, it's only closing the target storage postgresql db connection. but what happens after that? the analyzer goroutines may still be running. I think go keeps the process alive until those goroutines finish. but with no signal handler installed, a third ctrl+c does make the program exit

pro-wh

thanks for the changes

storage/oasis/nodeapi/history/runtime.go

Andrew7234

thanks!

mitjat requested review from aefhm, Andrew7234 and pro-wh as code owners April 27, 2023 19:46

pro-wh reviewed Apr 27, 2023

View reviewed changes

storage/oasis/nodeapi/file/consensus.go Show resolved Hide resolved

pro-wh reviewed Apr 27, 2023

View reviewed changes

cmd/analyzer/analyzer.go Outdated Show resolved Hide resolved

pro-wh reviewed Apr 27, 2023

View reviewed changes

mitjat requested a review from pro-wh April 27, 2023 21:02

pro-wh reviewed Apr 28, 2023

View reviewed changes

cmd/analyzer/analyzer.go Outdated Show resolved Hide resolved

mitjat force-pushed the mitjat/graceful-shutdown branch 3 times, most recently from 62cb459 to a3150be Compare April 29, 2023 04:04

mitjat requested a review from pro-wh April 29, 2023 04:08

ptrus reviewed Apr 30, 2023

View reviewed changes

mitjat force-pushed the mitjat/graceful-shutdown branch from 8467cd6 to 14f8632 Compare May 1, 2023 18:16

mitjat requested a review from ptrus May 1, 2023 18:17

pro-wh reviewed May 1, 2023

View reviewed changes

analyzer/evmtokenbalances/evm_token_balances.go Outdated Show resolved Hide resolved

pro-wh reviewed May 1, 2023

View reviewed changes

cmd/analyzer/analyzer.go Show resolved Hide resolved

pro-wh reviewed May 1, 2023

View reviewed changes

pro-wh approved these changes May 1, 2023

View reviewed changes

Andrew7234 reviewed May 1, 2023

View reviewed changes

storage/oasis/nodeapi/history/runtime.go Outdated Show resolved Hide resolved

Andrew7234 approved these changes May 1, 2023

View reviewed changes

mitjat added 8 commits May 1, 2023 16:00

analyzers, cache: Allow to shut down gracefully

6d15a89

Shut down gracefully on Ctrl+C

1b3ec82

pogreb constructor: rename filename->cacheDir

7a13ec0

KVStore: Encode keys with cbor, not gob

212adb5

KVStore: Add logging

727b113

Move cleanup actions from callers to functions-deferred-from-callee

87d228b

avoid double cleanup of API server

3c13d22

pass existing ctx to prework

1d47fe0

mitjat added 4 commits May 1, 2023 16:03

Log errors in cleanup handlers

71bc2a5

Let default handler handle the second ctrl+c

4d5cd5d

history API: close all supporting APIs even in case of errors

d1508be

FileApiLite: Close all resources

c4695c5

mitjat force-pushed the mitjat/graceful-shutdown branch from fa44ffa to c4695c5 Compare May 1, 2023 23:04

mitjat enabled auto-merge May 1, 2023 23:04

mitjat merged commit 377880d into main May 1, 2023
5 checks passed

mitjat deleted the mitjat/graceful-shutdown branch May 1, 2023 23:10

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

analyzers, cache: Allow to shut down gracefully #392

analyzers, cache: Allow to shut down gracefully #392

mitjat commented Apr 27, 2023 •

edited

pro-wh Apr 27, 2023

pro-wh Apr 27, 2023

pro-wh Apr 27, 2023

mitjat Apr 27, 2023

pro-wh Apr 28, 2023

mitjat Apr 29, 2023

pro-wh May 1, 2023

ptrus Apr 30, 2023 •

edited

pro-wh May 1, 2023

pro-wh May 1, 2023

pro-wh May 1, 2023 •

edited

pro-wh May 1, 2023

mitjat May 1, 2023

pro-wh May 1, 2023 •

edited

pro-wh left a comment

Andrew7234 left a comment

analyzers, cache: Allow to shut down gracefully #392

analyzers, cache: Allow to shut down gracefully #392

Conversation

mitjat commented Apr 27, 2023 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

ptrus Apr 30, 2023 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

pro-wh May 1, 2023 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

pro-wh May 1, 2023 • edited

Choose a reason for hiding this comment

pro-wh left a comment

Choose a reason for hiding this comment

Andrew7234 left a comment

Choose a reason for hiding this comment

mitjat commented Apr 27, 2023 •

edited

ptrus Apr 30, 2023 •

edited

pro-wh May 1, 2023 •

edited

pro-wh May 1, 2023 •

edited