Yet another attempt to fix the intermittent failure of gpg git test

[zeripath]

I think I've finally fixed the intermittent failure in gpg git test - The issue appears to be that occasionally the wrong/shutting-down fake server.

The fix appears to be in the integrations/git_helper_for_declarative_test.go where adding:

u.Host = listener.Addr().String()

Ensures that if there is more than one listener open the host will be updated for this.

I have run this PR on my local machine 30 times without reproducing the previous error.

[codecov-io]

Codecov Report

Merging #9146 into master will increase coverage by <.01%.
The diff coverage is n/a.

@@            Coverage Diff             @@
##           master    #9146      +/-   ##
==========================================
+ Coverage   41.01%   41.02%   +<.01%     
==========================================
  Files         553      553              
  Lines       72026    72026              
==========================================
+ Hits        29545    29547       +2     
+ Misses      38750    38749       -1     
+ Partials     3731     3730       -1

Impacted Files	Coverage Δ
models/unit.go	62.16% <0%> (-5.41%)	⬇️
models/repo_list.go	73.14% <0%> (-0.93%)	⬇️
routers/repo/view.go	38.59% <0%> (-0.88%)	⬇️
models/gpg_key.go	55.59% <0%> (+0.55%)	⬆️
modules/avatar/avatar.go	54% <0%> (+6%)	⬆️
modules/indexer/indexer.go	55.26% <0%> (+10.52%)	⬆️

---

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 055f6d2...785d768. Read the comment docs.

[zeripath]

Has built once so far without a failure. Will try to rebuild a few times to see if I can cause a failure.

[guillep2k]

@zeripath Last time (in master) failed with a nil pointer here:

		t.Run("AlwaysSign-Initial", func(t *testing.T) {
			PrintCurrentTest(t)
			testCtx := NewAPITestContext(t, username, "initial-always")
			t.Run("CreateRepository", doAPICreateRepository(testCtx, false))
			t.Run("CheckMasterBranchSigned", doAPIGetBranch(testCtx, "master", func(t *testing.T, branch api.Branch) {
				assert.NotNil(t, branch.Commit)
				assert.NotNil(t, branch.Commit.Verification)
				assert.True(t, branch.Commit.Verification.Verified)
				assert.Equal(t, "gitea@fake.local", branch.Commit.Verification.Signer.Email)
			}))
		})

The GPG code is very difficult for me to follow but apparently Signer was nil. This is a JSON deserialized structure, so it comes empty from gpg_key.go. My suspicion is that there are two db records that match a verified the signature, one with the proper signer and one without. The first one that matches is chosen, but them being two there's no guarantee it will be the "good one". So 99% of the time the good one passes and the other 1% fails.

[zeripath]

My suspicion was that the crud method was choosing an unsigned master as parent rather than a signed master - so changing the name of the repo should do it.

[guillep2k]

My suspicion was that the crud method was choosing an unsigned master as parent rather than a signed master - so changing the name of the repo should do it.

I'm not so sure about that, because this assertion was valid:

assert.True(t, branch.Commit.Verification.Verified)

[guillep2k]

I don't know how much longer the link will remain valid:

https://drone.gitea.io/go-gitea/gitea/16481/1/16

[zeripath]

It literally doesn't make sense. You cannot have assert.True(t, response.Verification.Verified) and yet have response.Verification.Signer be nil.

I just don't understand it.

[guillep2k]

Data for tests is fabricated, so anything goes. I've found several inconsistences in users/repos/issues/teams YAML on data that was crafted to pass a particular test but in a real site would break things. Maybe you're hitting one of those cases.

I'd suggest you add a debug print of the JSON responses for those tests just in case. That way if it fails again we will know for sure.

[guillep2k]

@zeripath thinking about it a little more, another possibility is that the assert for Verified didn't pass, but the message remained in a buffer unprinted when the panic was generated (that would make more sense maybe). Sorry if my comment made you chase a red herring.

[zeripath]

Yeah it must be that. In which case the commit isn't being signed for some reason.

[zeripath]

Maybe I should add failfast.

[zeripath]

OK I've pushed up some failnows and tests so the panic is avoided.

[zeripath]

well that still doesn't fix the failure!

[zeripath]

Aha: https://drone.gitea.io/go-gitea/gitea/16574/1/15

This failure proves that it is that the commit has not been signed not that we have a nil signer.

[zeripath]

This is a nightmare.

[zeripath]

Is it that the code generating the key occasionally produces a key that gpg does not like?

That would cause the failures in generating signed commits however it should fail always at the same point - the first signed commit.

So I don't think it can be that.

[guillep2k]

It must be something that is obviously non-deterministic, and since only seems to affect this test, my suspicions are:

• A race condition (anything that is being done in parallel and not serialized properly).
• Concurrent seemingly "valid" data which is not; e.g. two or more records that match the signing process where normally the first (the good one) is selected, but a second exists that have some chance of showing up, due to different I/O scheduling.

Question: why are we running so many onGiteaRun()? Can't it all be done in a single onGiteaRun()? I believe that those will be run in parallel; so we are looking for trouble by doing it that way, IMHO.

[zeripath]

I tried it originally in one onGiteaRun - my previous "fix" split it in to many because I thought it was possible that the intermittent failure was due to sync errors from changed settings not being propagated to running goroutines as we don't synchronize.

Perhaps that's still the case ? Even despite the code in onGiteaRun trying to wait for the listener to close? There are other goroutines running during integration tests afaics so I guess unsynchronized changes to setting are possible.

Maybe it needs some more log.Trace() - however if there is a race then that might simply remove the race.

I just don't know where the problem is. It could be anywhere in the signing decision tree:

• Gitea doesn't think it should be signed because settings haven't propagated (or it's even trying to look at the wrong thing)
• Signing fails due to gpg weirdness
• Verification of the signature fails

I guess I've not systematically figured out which one is the problem - therefore extensive log.Trace is the only way to figure out what's happening - but hopefully that doesn't break the race. I guess I could stick extensive log.Traces at 2 of the 3 places. If the race stops we know it's one of those places, but if not and the logging makes sense then we know it's in the final place?

[guillep2k]

I tried it originally in one onGiteaRun - my previous "fix" split it in to many because I thought it was possible that the intermittent failure was due to sync errors from changed settings not being propagated to running goroutines as we don't synchronize.

Hummm... 🤔 What do you mean by "propagate"?; any changes will be instantaneous unless 1) a process using its value already started or 2) a setting is derivative of the value and has already been calculated (it's the same as (1) but from a different perspective).

A quick check gives me that the following settings are checked right before they are used:

• setting.Repository.Signing.CRUDActions @ func (repo *Repository) SignCRUDAction()
• setting.Repository.Signing.InitialCommit @ func (repo *Repository) SignInitialCommit()
• setting.Repository.Signing.Merges @ func (repo *Repository) SignMerge()

So changing them before the call will make the function accept the new values. Unless you call it from several goroutines at once, which is what you're currently doing by parallelizing several onGiteaRun().

[zeripath]

So, here's where we're into synchronisation issues... I'm not completely certain on the go memory model but is it guaranteed that if you have a variable and you change it in one goroutine that the other will know it? I thought they would require a lock to ensure that the other goroutine knows that the data had changed.

In java if you wanted to change data on objects you absolutely had to pass through a lock to guarantee that all threads would get the same data - that was probably partially because of the JIT but also to do with CPU caches.

It's a fairly hard thing to prove definitively as you need to not pass through a lock - I'm fairly certain that os.Stdout will hit a lock so that might not work.

[guillep2k]

So, here's where we're into synchronisation issues... I'm not completely certain on the go memory model but is it guaranteed that if you have a variable and you change it in one goroutine that the other will know it? I thought they would require a lock to ensure that the other goroutine knows that the data had changed.

AFAIK no, this is not the case. You need locks to keep consistency, not to announce anything. Locks are not channels. Locks simply prevent threads from accessing resources at the same time, provided the other threads also use the same lock objects in the same way.

[guillep2k]

In java if you wanted to change data on objects you absolutely had to pass through a lock to guarantee that all threads would get the same data - that was probably partially because of the JIT but also to do with CPU caches.

You mean memory barriers? You only can have that with "sync/atomic", mostly for primitive data types (e.g. int, int64) or using atomic.Store()/Load().

[lafriks]

Please resolve conflicts and rebase on latest master

[zeripath]

Rebased.