refactor: log server listening observations after listening socket is ready

[taimoorzaeem]

We were logging these observations before running the server. If the server fails to startup, it was a bit misleading because one could think that something went wrong after the listening has already started which might not be true.

Previous behaviour that was tested manually by instrumenting the code:

  observer $ AdminServerObs address
  void . forkIO $ do
    _ <- throwIO $ ErrorCall "admin crash"
    Warp.runSettingsSocket settings adminSocket adminApp

The observation got logged even though the server didn't start at all. With the fix, that doesn't happen.

Related #5012.

[mkleczek]

It would be good to add a couple of IO tests:

• happy path (ie. observations are logged)
• failure path (ie. observations are not logged) - not sure how easy it is to simulate but maybe starting two PostgREST instances on the same ports should cause the second one to fail listening?

[taimoorzaeem]

* happy path (ie. observations are logged)

Opened #5039 for this. 👍

* failure path (ie. observations are **not** logged) - not sure how easy it is to simulate but maybe starting two PostgREST instances on the same ports should cause the second one to fail listening?

This isn't easy to reproduce. Running two instances doesn't work because socket initialization happens before the observation gets logged. I think the only way to reproduce this is to somehow kill the admin server thread before it starts listening, which to me seems not possible (even if it is — not worth it, I think).

[wolfgangwalther]

Since we have yet to prove that this is a problem that could even appear in reality, I'd argue this is a straight refactor at this point. The only scenario where this happened was when changing the code to not actually listen on the admin socket. Well, of course in this case the observation is wrong.

I do agree with the refactor here, because it's obviously more correct: We should log the observation after the thing happened, not before.

But I would certainly not bother trying to reproduce this hypothetical case with a test.

(the issue that this came up is different - this is about the admin server dying later, in which case the observation was correct, because it was up at some point. Edit 2: After re-reading the issue, I'm not sure whether that understanding is correct. @steve-chavez could you clarify whether that comes up right when starting PostgREST - or after a while only?)

Minus the commit message prefix: LGTM.

Edit: To be clear: No judgement on whether this is the best refactoring, the proposal in #5037 (comment) could very well be better - I don't know.

[steve-chavez]

I'm not sure whether that understanding is correct. @steve-chavez could you clarify whether that comes up right when starting PostgREST - or after a while only?

Will answer that on #5012, so far we don't know.

Minus the commit message prefix: LGTM.

Agree in that as it is it should be a refactor only.

[steve-chavez]

Minus the commit message prefix: LGTM.
Agree in that as it is it should be a refactor only.

Come to think of it, it is a `partial fix" in that if the Admin server thread fails to start somehow, we won't log that the admin server started successfully, which is misleading. That being said, this "partial fix" is not that useful for the users since they can't do anything besides restart when this happens.

I've put the steps for the complete fix on #5012 (comment). Can be done here or on another PR.

[taimoorzaeem]

I agree that this is really just a refactor.

I think 99% of the time, the thread failing to start would only occur when the system is out of resources (mem/cpu), but at the point, PostgREST won't start at all, so the above scenario would never really happen.

Will merge this as refactor for now. Gonna continue discussion on the fix in #5012.