@polarathene do you have any idea, btw, why the test job does not use the cache from the build job?

So, I know, not pretty - but I spent too much time yesterday without really getting down to it. Therefore, I figured, adding the sleeps is not a permanent solution, but for the time being, better than an always-failing CI.

sleeps is not a permanent solution, but for the time being, better than an always-failing CI.

I haven't looked in detail in this current issue. But another pragmatic approach could be: find out, when the failing tests started and then revert the last changes made to the tests? That should fix it or am I wrong.

Anything was introduced that caused that issue. So instead of fixing the symptoms, I would roll back the change that introduced the issue in the first place.

sleeps is not a permanent solution, but for the time being, better than an always-failing CI.

I haven't looked in detail in this current issue. But another pragmatic approach could be: find out, when the failing tests started and then revert the last changes made to the tests? That should fix it or am I wrong.

IIRC #2729 showed that CI is fragile. While I do not think #2729 introduced a bug, it unveiled the fragility. That's why it is hard to pinpoint: there is no obvious change that serves as the cause.

Anything was introduced that caused that issue. So instead of fixing the symptoms, I would roll back the change that introduced the issue in the first place.

As I said above, this works in theory, but it is more or less difficult in this case for the reasons mentioned above.

I'm not for introducing sleep as well, but unless someone else finds the cause (which may take time), I prefer it over restarting CI 3 or 4 times.

@polarathene do you have any idea, btw, why the test job does not use the cache from the build job?

The build job did not create a new cache. It had a primary key cache hit. The file contents that derive the cache key has been seen by the CI before.

When this happens, if something has changed that invalidates that cache, unfortunately the cache action does not upload a new cache, this only happens when the expected cache key for the contents (the primary key that we used) didn't have a match and a fallback cache key was used.

So we restored a previous cached build, that for some reason uploaded the build cache that for the same key still got it invalidated. I only remember this happening when I worked on the feature and ARG was invalidating the build, or there was something causing incorrect cache key generation.

I am wondering if we implemented the re-usable workflows correctly, or if they're incompatible here. I'd need to check the cache key generated is for this PR contents or if it was generating that from master?

Cache key CI used: cache-buildx-a0ceadd91401151c4991b14c3f1e2d38e77032937df0f7d9dcf9a12582b50b89

I just noticed this is quite a problem with commits on master often failing to pass/complete the Build, Test & Deploy workflows.

As suspected... (EDIT: Tracked down where the key was from and why it hasn't changed, totally fine)

Cache restored from key: cache-buildx-a0ceadd91401151c4991b14c3f1e2d38e77032937df0f7d9dcf9a12582b50b89

That is the same cache key used by this PR CI build/test, as was used on Master for merging of this recent PR. That was also the cache key used in that PRs last commits (merges from master, that was the specific job that generated the cache key quoted above) which isn't too surprising. We can also see that non-merge commits in that PR was using different cache keys as they should (this ones build step restored a fallback key, then generated a new one, that was used to restore cache in future commits on the PR and generate the same cache key for the image build being used here).

Oh ok, just noticed that this PR doesn't contribute anything that should cause a new image cache key to be created, so it appears to be behaving correctly.

Looking back at the related PR merge commit on master and the CI build job there, it does not have the known build cache key from the PR due to the security scoping stuff, it needs to do a fresh build/cache upload of that. And we see that it selects and restores the cache-buildx cache key, which isn't valid but was created as a bug AFAIK, if that hasn't been evicted after 7 days of whenever it was created, Github might renew the expiry if it's accessed within the past 7 days?

Anyway, that cache from whenever that was, is invalidated and we get a fresh build. At the end of the build job, since we did not restore a primary cache key for the given contents, it uploads to master branch cache the same key this PR is using. Now any branch/PR that derives this cache key should have access to that, and it should be the most recent fallback cache key used too presently.

I am not sure what exactly is causing this invalidation, but I can see that your previous version of this PR was able to build using the cache for this same cache key:

#9 [internal] load metadata for docker.io/clamav/clamav:latest
#9 DONE 0.2s

#8 [internal] load metadata for docker.io/library/debian:11-slim
#8 DONE 0.4s

#10 importing cache manifest from local:3943879211245529940
#10 DONE 0.0s

#11 FROM docker.io/clamav/clamav:latest@sha256:0353dfffc8e8d6e035208e380cdc0f7f64299b849acef4b20ca8d87d874ba409
#11 resolve docker.io/clamav/clamav:latest@sha256:0353dfffc8e8d6e035208e380cdc0f7f64299b849acef4b20ca8d87d874ba409 done
#11 DONE 0.0s

#12 [stage-base  1/47] FROM docker.io/library/debian:11-slim@sha256:5cf1d98cd080595[148](https://github.com/docker-mailserver/docker-mailserver/actions/runs/3170398519/jobs/5162954169#step:7:151)4f33b34c1ab25aac7007bb41c8b9901d97e4be3cf3ab04
#12 resolve docker.io/library/debian:11-slim@sha256:5cf1d98cd0805951484f33b34c1ab25aac7007bb41c8b9901d97e4be3cf3ab04 0.0s done
#12 DONE 0.0s

#13 [internal] load build context
#13 transferring context: 290.82kB 0.0s done
#13 DONE 0.1s

#14 [stage-base 21/47] RUN <<EOF (chmod 755 /etc/init.d/postgrey...)
#14 CACHED

Your last commit on that PR that built with cache was: properly provide ENV, afterwards it started invalidating cache. Nothing stands out as the cause though.

I'm not for introducing sleep as well, but unless someone else finds the cause (which may take time), I prefer it over restarting CI 3 or 4 times.

It's fine for now and I doubt we're going to benefit much time wise by reverting. It's a minor hit considering how long tests normally take, and we know that the sleep part aside, we're not implicitly hiding the timing problems that were surfaced by recent additions to tests.bats.

However, we can do better:

These are the methods you're adding sleep around, and apart from the helper I wrote with a fixed 60 seconds (and advice to wait on postfix/dovecot after separately if necessary), we can see a common way to avoid the sleeps so that they're only optional when needed:

If 15 secs of sleep is really all that's required, surely we could just bump up the default a bit more. Otherwise I'd expect failures to still occur and increasing sleep each time isn't going to be any different? You could bump that up from 2 minutes to 3, more than enough padding.

If we still get failures, it's not a fix that extra time is likely to resolve, and more an indication that something else is going wrong (as has been suggested in the earlier version of this PR for what we could try).

Additionally as per my comments here, we can switch check-for-changes.sh to have Postfix and Dovecot use reload instead of restart, as that should minimize any race conditions from the downtime of restart. It's quite possible since we are handling change detection in the middle of the setup.

I also suggested considering wait_for_service "${TEST_NAME}" postfix directly after wait_until_change_detection_event_completes is called if we're to wait on ensuring Postfix is ready.

Very nice investigative work @polarathene!

I think this PR has some nice additions too that should make it into v12 later :) Feel free to review :D

PS: Sorry for the force-push - forgot to sign the commit.

I have changed the title as @casperklein proposed (it was indeed not fitting anymore).