add(observation): db pool flushes observation

[mkleczek]

Emit a dedicated PoolFlushed observation when the DB pool is released during schema cache reload.

[steve-chavez]

This is interesting, so we use the newChan instead of logging to stdout/stderr right?

What would be the advantage of this over the python tests?

[mkleczek]

This is interesting, so we use the newChan instead of logging to stdout/stderr right?

Haskell makes it so easy to add new observers (Observation -> IO () is a Semigroup) that it is too tempting not to use it :)

What would be the advantage of this over the python tests?

More seriously (this is a mix of more or less subjective opinions):

It is not really clear to me what is the project policy on "what tests should go where". My take on this is that I really think it is quite a bad idea to base your business logic tests on debug output.

I spent a considerable amount of time chasing failing io tests after adding this new observation and was really annoyed with the experience. So decided to move to HSpec tests instead.

I think HSpec tests are really well suited for logic testing. They are type safe and make refactoring easy. Also, reading observations as a stream of typed messages in tests (instead of untyped string debug output) makes the tests less brittle and more readable IMHO.

Chan is a simple but powerful concurrency primitive and, IMHO, perfect fit for testing asynchronous messaging scenarios. See https://github.com/PostgREST/postgrest/pull/4668/changes#diff-0f4d50d33174e92e7c2b8121202cbcb7923360111854c13c2f4baa9eadb80602R44 in this PR. Thanks to some higher level functions based on Chan and dupChan we have a simple DSL to validate observations that also provides nice error messages that simplify debugging.

[steve-chavez]

I spent a considerable amount of time chasing failing io tests after adding this new observation and was really annoyed with the experience. So decided to move to HSpec tests instead.

Agree, I've had the same experience before.

My take on this is that I really think it is quite a bad idea to base your business logic tests on debug output.
Also, reading observations as a stream of typed messages in tests (instead of untyped string debug output) makes the tests less brittle and more readable IMHO.

Agree too. I like the direction overall.

---

Sometimes we've had cases where the ordering of the log messages change and that was reflected in tests. Say if we decided to move all logging python tests to Haskell, would a change in the order be detected too? (order does matter in some cases, for clarity)

[mkleczek]

Sometimes we've had cases where the ordering of the log messages change and that was reflected in tests. Say if we decided to move all logging python tests to Haskell, would a change in the order be detected too? (order does matter in some cases, for clarity)

That depends on how observations order is related to debug log entries order. They should be the same but we don't test it in HSpec tests - we only read observations from a Chan.
There is a simple helper function waitFor which reads from the Chan skipping messages until it reads the message meeting provided criteria (or hangs waiting for an observation (or timeout) if none available). I think it is sufficient primitive for most cases.
You can test if required observations happen in right order (but possibly with other observations in between), eg:

        waitFor (2 * sec) "PoolFlushed 2" $ \x -> [ o | o@PoolFlushed <- pure x ]
        waitFor (1 * sec) "SchemaCacheLoadedObs" $ \x -> [ o | o@SchemaCacheLoadedObs{} <- pure x ]

This will skip SchemaCacheQueriedObs in between.

If necessary we can implement non-lenient validation.

Let's move this discussion to #4671 (comment)