Add logging to catch testing race-condition

[itaiad200]

Reenabling and adding logging for #3428

I retry the test >10 times and it didn't fail. Esti's history shows that it failed twice in the recent 150 runs, so we need it enabled (with better logging) if we want to catch that race condition.

[arielshaqed]

I am confused by the disparity between what this code does and what the linked code does -- they seem to handle "connection refused" errors very differently from one another.

[arielshaqed]

Would it make sense to ensure that only one of these operations is being performed? Otherwise someone might add a new operation and not think to avoid it being retried.

[itaiad200]

That's not an exhaustive list, other operations may also benefit from it. I'll update the comment to reflect that.

Notice that even before this change, the caller must always assumes that a retry may happen. This change only adds one more case where a specific tcp error is retried.

[arielshaqed]

This condition is not only strange, it also looks like the opposite of isConnectionReset. For some reason, AWS consider a "connection reset" to be a connectionReset only if it is not a "read: connection reset".

I don't understand it.

[itaiad200]

Yap - I think the linked code is confusing. The appropriate function name should be isErrConnectionResetAndShouldRetry

[arielshaqed]

Can you do something like what this StackOverflow answer suggests? It should work if AWS errors wrap OS errors (in the golang sense) -- and if it is good, it is much better than looking at the error message.

Also worried about the "read:" prefix.

[arielshaqed]

Had a look at AWSErr, and it seems not to wrap. But you can try to cast to an AWSError, and if that succeeds call OrigErr. I don't see OrigErr as returning the BatchError case except for errors from the S3 manager, so probably safe to ignore that.

So something like

if awsErr, ok := err.(awserr.Error) {
	err = awsErr.OrigErr()
}
return errors.Is(err, syscall.ECONNRESET)

might work!!?!
}

[arielshaqed]

Actually, can you explain what the scenario this retrier fixes in the flaky test? Why is the service under test stopping before the test is done?

[arielshaqed]

Can you do something like what this StackOverflow answer suggests? It should work if AWS errors wrap OS errors (in the golang sense) -- and if it is good, it is much better than looking at the error message.

Also worried about the "read:" prefix.

[N-o-Z]

You have a typo in the filename

[N-o-Z]

@itaiad200 Did you see TestPyramidWriteFile failure?

[arielshaqed]

Thanks!

1. Note that logging adds a lot of synchronization that can destroy many race conditions.
2. I would add some field to the loggers passed in (say test: true or something) to make it easier to see their result.

Rather than push it onto master, could we perhaps just run it 30 times and see if we get a failure with interesting logs?

[arielshaqed]

weird gofmt.

[itaiad200]

Aligned to the right 🤷‍♂️

[itaiad200]

@itaiad200 Did you see TestPyramidWriteFile failure?

Nope, this location where I added logs is the context I'm afraid we're cancelling prematurely.

[itaiad200]

Thanks!

1. Note that logging adds a lot of synchronization that can destroy many race conditions.
2. I would add some field to the loggers passed in (say test: true or something) to make it easier to see their result.

Rather than push it onto master, could we perhaps just run it 30 times and see if we get a failure with interesting logs?

It's the Esti test that has flakiness, not TestPyramidWriteFile. I wrote about the previous runs (2 failures in ~150 runs), I think that this log will help us catch it the next time.