otelhttptrace: handle missing getconn hook without panic

[tonistiigi]

We have many reports that end() gets called without the span being defined in start() and causes a panic.

Ref moby/buildkit#4377
Ref docker/buildx#2232

I have not not fully debugged in what condition this happens in stdlib (I assume some keepalive pool case) but I don't see any other possible explanation for these panic cases.

Note that there are other httptrace hooks that also use .root without validation. I don't atm. have any proof that these could be called without GetConn() being called first as well so didn't add extra validation to these.

[codecov]

Codecov Report

Attention: Patch coverage is 0% with 2 lines in your changes missing coverage. Please review.

Project coverage is 64.4%. Comparing base (669ca60) to head (ded1cd2).

Additional details and impacted files

@@           Coverage Diff           @@
##            main   #5187     +/-   ##
=======================================
- Coverage   64.5%   64.4%   -0.1%     
=======================================
  Files        200     200             
  Lines      12558   12560      +2     
=======================================
- Hits        8103    8101      -2     
- Misses      4219    4221      +2     
- Partials     236     238      +2     

Files	Coverage Δ
...on/net/http/httptrace/otelhttptrace/clienttrace.go	79.0% <0.0%> (-0.8%)	⬇️

... and 1 file with indirect coverage changes

[dmathieu]

This change only handles missing span in end() if useSpans is false.
It seems like that could also happen with the use of sub spans as well.

Also, I know this is hard to reproduce, and this package doesn't really have any tests at the moment, but would it be possible to write a test?

[tonistiigi]

This change only handles missing span in end() if useSpans is false.
It seems like that could also happen with the use of sub spans as well.

What place/variable do you have in mind?

Also, I know this is hard to reproduce, and this package doesn't really have any tests at the moment, but would it be possible to write a test?

These calls are made from stdlib and I don't know the condition when the specific call order appears.

[pellared]

These calls are made from stdlib and I don't know the condition when the specific call order appears.

I think the main usage of httptrace.ClientTrace is here: https://github.com/golang/go/blob/master/src/net/http/transport.go

[alessandrozucca-p]

We started seeing this as well after introducing the option otelhttptrace.WithoutSubSpans()

The original implementation was taking locks at the beginning on the function:

func (ct *clientTracer) end(hook string, err error, attrs ...kv.KeyValue) {
ct.mtx.Lock()

defer ct.mtx.Unlock()

However since the introduction of if !ct.useSpans { the locks are not taken immediately.

It made me wonder, could this have cause some race condition?

[dmathieu]

Could this be tested?

[xocasdashdash]

as @tonistiigi mentioned, they've gotten some reports, there's very little consistency on when this happens. We've seen very similar problems with clients very rarely blowing up with this same error.

I'm assuming this is going to be very hard to test because of this.

[dmathieu]

A unit test doesn't have to be a full reproduction. It can call end() with conditions that reproduce this case, just to ensure the code path doesn't fail.

[krantideep95]

I have created a new pull request #5965 which adds unit test for end() func

[dmathieu]

This will need a changelog entry.

[tonistiigi]

Added changelog

[krajorama]

Hi, just ran into moby/buildkit#4377 . Any update on this PR? I understand only unit test is missing?