Fix wrong name tag for HTTP metrics from redirects #1570

imiric · 2020-07-23T08:56:44Z

The root cause was reusing the same 'name' tag for all requests processed by a transport. In the case of redirects and digest auth the transport would process more than one request and needs to update the 'name' tag in the same way as 'url' is. For the initial request we need the originally parsed one to be consistent with the credential masking feature (as this gets stripped in the request passed to RoundTrip()), and tags for subsequent requests will be dynamically generated.

I'm not sure if this confirms @mstoykov's gut feeling that it will break aggregation somehow, but I'd argue this is the correct approach so we'll have to deal with it. 😄

I didn't add more tests for this as the current ones are quite thorough.

codecov-commenter · 2020-07-23T09:03:11Z

Codecov Report

Merging #1570 into master will decrease coverage by 0.01%.
The diff coverage is 100.00%.

@@            Coverage Diff             @@
##           master    #1570      +/-   ##
==========================================
- Coverage   73.91%   73.90%   -0.02%     
==========================================
  Files         165      165              
  Lines       14519    14521       +2     
==========================================
  Hits        10732    10732              
- Misses       3224     3225       +1     
- Partials      563      564       +1

Impacted Files	Coverage Δ
lib/netext/httpext/request.go	`96.04% <100.00%> (-1.24%)`	⬇️
lib/netext/httpext/transport.go	`96.62% <100.00%> (+0.37%)`	⬆️
lib/testutils/minirunner/minirunner.go	`78.57% <0.00%> (-3.58%)`	⬇️
lib/executors.go	`94.11% <0.00%> (+1.96%)`	⬆️

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 0737194...bfd7a29. Read the comment docs.

lib/netext/httpext/transport.go

na-- · 2020-07-23T10:53:46Z

After my initial dumb comment, I'll try to make one that's a bit more informed, albeit in the same direction... 😅

For the initial request we need the originally parsed one to be consistent with the credential masking feature (as this gets stripped in the request passed to RoundTrip()), and tags for subsequent requests will be dynamically generated.

Looking at this code: https://github.com/loadimpact/k6/blob/5ff4a76a4a08241ce061fcc449be585f7f707e6a/lib/netext/httpext/digest_transport.go#L43-L57

I'm thinking we shouldn't bother with numProcReqs and the special handling at all, since this logic is trying to mask something we don't actually do. The current HTTP digest logic actually makes an initial request without authentication, so we should emit it like it happens, not try to mask it.

We should definitely fix the current dumb digest implementation (#800), but we shouldn't try to pretend it doesn't do the stupid things it does...

imiric · 2020-07-23T10:55:55Z

@na-- Ah, even better! I thought this request came from stdlib and not from our code. Thanks, will fix.

na-- · 2020-07-23T10:57:37Z

Unfortunately, stdlib still doesn't have digest authentication, so we've had to make do with external libraries. The current one is the second attempt IIRC, and it also sucks. As explained in that issue, we need some substantial refactoring, including a per-VU credential cache or something like that, to fix the issue we currently have of making 2 HTTP requests every time... 😞

Resolves? #1570 (comment)

imiric · 2020-07-23T15:41:38Z

@na-- Unfortunately, I don't think we can get rid of some wonkiness here. :-/

Besides the digest credential masking, the original URL name is also needed to keep the metrics aggregatable on the same query params. So @mstoykov was right, and this will make subsequent requests not part of this group, but there's a point to be made that they should be aggregated differently since the original query string isn't passed to these later requests anyway. Though the name tag seems to be abused for several purposes, so we might want to rethink that at some point.

I got rid of the counter in 4f30941, but some state change is still needed to set this tag for only the first request. Wiping the string after the first pass seems slightly better, but still not great. Let me know.

na-- · 2020-07-24T11:47:27Z

lib/netext/httpext/transport.go

+			// If a name tag is already set in the script, use it for all requests
+			// processed by this transport. Otherwise, use the original URL name
+			// to preserve any escaped query string arguments, but only for the
+			// first request in the chain.
+			if t.origURLName != "" {
+				tags["name"] = t.origURLName
+				t.origURLName = ""


This still seems strange... if a name tag was set by the user in the script, wouldn't it be in the t.tags map above? 😕

ah, nevermind, "spoke" too soon again - this comment is about the if _, ok := tags["name"]; !ok part of the check...

still, I continue to not understand why we need the original URL, when cleanURL should suffice 😕

Because otherwise this test fails.

I'm trying to see if I can clean it again in the transport the same way while preserving the escaped query args, but I'm not functioning on all cylinders today. :-/

Because otherwise this test fails.

Ahhh... welll... 💩 😅 Yeah, I'll have to scratch my head about this some more, but the current version of this PR might be as good as it gets... 😞 Not sure why anyone added this (on the bottom of that section) funky way of specifying URLs, but now we have to live with it... 😭 It implies a name tag, but it doesn't specify it, instead using this weird k6-specific URL struct, which of course we can't propagate in an http.RoundTrippter 😭 And thus, I finally understand the purpose of all of the weird fixes in this PR 😅

Let's discuss this on Monday again, but I'm thinking that if someone uses something like this:

http.get(http.url`http://example.com/posts/${id}`)

we probably should consider it as if they used

http.get(`http://example.com/posts/${id}`, {tags: {name: 'http://example.com/posts/${}'}})

That is, if there are any redirects in the course of that HTTP request, all of their name tags should be 'http://example.com/posts/${}'. Or, said otherwise, #1474 is not a bug when the user has explicitly used the http.url tagged template.

OK, I think that should be the case in 62f9184. The only wonky thing is the obscure preq.URL.Name != preq.URL.CleanURL check, which works when a tagged template string is used.

This does break the masked credentials behavior for digest auth, i.e. the generated name tag in these cases won't be https://****:****@<host>... anymore, but https://<host>. I discussed this with @na-- the other day, so this might be acceptable, and if so we should mention it in the release notes.

…r http.url is used Resolves #1570 (comment)

mstoykov

Will take another look (mostly at the tests ;) in an hour

But it seems like it's fine and is smaller change then it was before 🎉

Also relevant (but not useful for us) addition in golang 1.15 https://tip.golang.org/pkg/net/url/#URL.Redacted

mstoykov · 2020-07-24T16:15:55Z

js/modules/k6/http/request_test.go

@@ -181,7 +181,7 @@ func TestRequestAndBatch(t *testing.T) {
 			}

 			assert.Equal(t, 10, reqsCount)
-			assertRequestMetricsEmitted(t, bufSamples, "GET", sr("HTTPBIN_URL/get"), sr("HTTPBIN_URL/redirect/9"), 200, "")
+			assertRequestMetricsEmitted(t, bufSamples, "GET", sr("HTTPBIN_URL/get"), sr("HTTPBIN_URL/get"), 200, "")


Can we check that we got 302 for all the others in this case? Or at least one-two

Also (not really related to this PR) ... assertRequestMetricsEmitted having so many fields is not great ( I needed to go look up what all the fields are).

Also not great is that there is logic for empty name being equal to url, which you used below, but not here ...

I do think that that logic should be dropped and we should always provide the name ... maybe at least for this PR

cc @na--

I don't understand the question, sorry.

I don't think

assertRequestMetricsEmitted(t, bufSamples, "GET", url, "", 200, "")

should mean

assertRequestMetricsEmitted(t, bufSamples, "GET", url, url, 200, "")

I also do think that it will be nice if ... I dunno this is

assertRequestMetricsEmitted(t, bufSamples, expectmetric{ method: "GET", url: url, name:"", status: 200, whateverThisIs: "", })

For this PR maybe just write the name for the other tests, instead of leaving it ""

Ahhh, ok, yeah, url, "" is confusing, 👍 👍 for url, url,... A full refactoring of the test can wait for a future PR though 😄

I added the redirect checks in 70144e8, and while I agree that the name = url override is unnecessary, I'd rather leave that change for a follow-up PR.

Changed this to check all redirects in e6b65c8.

mstoykov · 2020-07-27T09:28:31Z

lib/netext/httpext/transport.go

+		cleanURL := URL{u: unfReq.request.URL, URL: unfReq.request.URL.String()}.Clean()
 		if enabledTags.Has(stats.TagURL) {
-			u := URL{u: unfReq.request.URL, URL: unfReq.request.URL.String()}
-			tags["url"] = u.Clean()
+			tags["url"] = cleanURL
+		}
+
+		if _, ok := tags["name"]; !ok && enabledTags.Has(stats.TagName) {
+			tags["name"] = cleanURL
+		}


I would've really prefered it, if cleanURL is created only if it's needed :D

I changed this in 8872f4a, at the expense of duplication, though I'm not sure it will be more efficient overall, as most of the time both url and name tags will be provided. We can add additional checks, but I don't want to complicate this too much.

Resolves #1570 (comment)

js/modules/k6/http/request_test.go

Resolves? #1570 (comment)

…r http.url is used Resolves #1570 (comment)

Resolves #1570 (comment)

mstoykov

LGTM, I haven't tested it ... but the test looks fine.
I vote tentatively for leaving this for v0.29.0 (and merging it early on this time ;) ) just because of the nature of the change and (IMO) low priority of the issue given this has been the case forever and nobody has complained

mstoykov · 2020-09-04T09:44:45Z

lib/netext/httpext/transport.go

+			cleanURL := URL{u: unfReq.request.URL, URL: unfReq.request.URL.String()}.Clean()
+			tags["url"] = cleanURL
+		}
+
+		if _, ok := tags["name"]; !ok && enabledTags.Has(stats.TagName) {
+			cleanURL := URL{u: unfReq.request.URL, URL: unfReq.request.URL.String()}.Clean()
+			tags["name"] = cleanURL
+		}


To be honest given the high amount of code that will execute those, I would prefer if we do actually do this in (pseudo code):

var urlEnabled = enabledTags.Has(url)...; var nameToBeSet = <the whole if>; if urlEnabled || nameToBeSet { cleanUrl = ... if urlEnabled { tags["url"] cleanURL } if name....

both are likely to be true always and I would argue it isn't the worst code out there

Sure, makes sense, see 8ee1d1c.

na-- · 2020-09-04T10:04:53Z

We've been delaying this for quite a while, so I vote for v0.28.0. If there's a bug in this, it's unlikely to be worse than the bug that currently exists... The fact that nobody has commented on it probably means that most people use url and not name, or they just haven't noticed the issue in the cloud tests...

Resolves #1570 (comment)

na--

LGTM

mstoykov · 2020-09-04T12:29:36Z

lib/netext/httpext/transport.go

+			if urlEnabled {
+				tags["url"] = cleanURL
+			}
+			if _, ok := tags["name"]; !ok && nameEnabled {


I am pretty sure I am becoming a PITA, but can you move the _, ok := tags["name"]; !ok in the above if? or better yet in the nameEnabled ;)

I am pretty sure I am becoming a PITA

Only a bit :)

Is 413d0fe what you had in mind? I think I preferred the previous version, but out of curiosity, why is this better?

you could have had name set and url disabled and you would've stilled cleaned the url and then found out you didn't need it

#1570 (comment)

na--

Can we (squash+)merge this now? 😅

Closes #1474 The root cause was reusing the same 'name' tag for all requests processed by a transport. In the case of redirects and digest auth the transport would process more than one request and needs to update the 'name' tag in the same way as 'url' is, but only for the initial request, as subsequent ones will by dynamically generated.

imiric · 2020-09-04T12:59:39Z

Sorry guys, please approve one last time. I wanted to squash the fix separately from the .gitignore change, so had to do it manually.

mstoykov

No problem @imiric ;)

imiric requested review from mstoykov and na-- July 23, 2020 08:56

na-- reviewed Jul 23, 2020

View reviewed changes

lib/netext/httpext/transport.go Outdated Show resolved Hide resolved

imiric pushed a commit that referenced this pull request Jul 23, 2020

Refactor name tag fix, remove counter

4f30941

Resolves? #1570 (comment)

na-- reviewed Jul 24, 2020

View reviewed changes

imiric pushed a commit that referenced this pull request Jul 24, 2020

Only set the name tag for all requests in a chain if explicitly set o…

62f9184

…r http.url is used Resolves #1570 (comment)

mstoykov reviewed Jul 27, 2020

View reviewed changes

imiric pushed a commit that referenced this pull request Jul 27, 2020

Check redirect request metrics in TestRequestAndBatch

70144e8

Resolves #1570 (comment)

imiric pushed a commit that referenced this pull request Jul 27, 2020

Only clean URL when generating enabled tags

8872f4a

Resolves #1570 (comment)

mstoykov reviewed Sep 3, 2020

View reviewed changes

js/modules/k6/http/request_test.go Outdated Show resolved Hide resolved

js/modules/k6/http/request_test.go Outdated Show resolved Hide resolved

js/modules/k6/http/request_test.go Outdated Show resolved Hide resolved

js/modules/k6/http/request_test.go Outdated Show resolved Hide resolved

Ignore .log files

65372c5

imiric pushed a commit that referenced this pull request Sep 4, 2020

Refactor name tag fix, remove counter

22e6250

Resolves? #1570 (comment)

imiric pushed a commit that referenced this pull request Sep 4, 2020

Only set the name tag for all requests in a chain if explicitly set o…

e6b3814

…r http.url is used Resolves #1570 (comment)

imiric pushed a commit that referenced this pull request Sep 4, 2020

Check redirect request metrics in TestRequestAndBatch

e6b65c8

Resolves #1570 (comment)

imiric pushed a commit that referenced this pull request Sep 4, 2020

Only clean URL when generating enabled tags

a78ab42

Resolves #1570 (comment)

imiric force-pushed the fix/1474-name-tag branch from ff6acc3 to a780923 Compare September 4, 2020 09:12

imiric requested review from mstoykov and na-- September 4, 2020 09:23

mstoykov previously approved these changes Sep 4, 2020

View reviewed changes

imiric pushed a commit that referenced this pull request Sep 4, 2020

Call URL.Clean() only once when setting metric tags

8ee1d1c

Resolves #1570 (comment)

imiric dismissed mstoykov’s stale review via 8ee1d1c September 4, 2020 10:18

na-- previously approved these changes Sep 4, 2020

View reviewed changes

mstoykov reviewed Sep 4, 2020

View reviewed changes

imiric pushed a commit that referenced this pull request Sep 4, 2020

Check name tag as per Mihail's wishes :)

413d0fe

#1570 (comment)

imiric dismissed na--’s stale review via 413d0fe September 4, 2020 12:49

na-- previously approved these changes Sep 4, 2020

View reviewed changes

mstoykov previously approved these changes Sep 4, 2020

View reviewed changes

imiric dismissed stale reviews from mstoykov and na-- via bfd7a29 September 4, 2020 12:59

imiric force-pushed the fix/1474-name-tag branch from 413d0fe to bfd7a29 Compare September 4, 2020 12:59

na-- approved these changes Sep 4, 2020

View reviewed changes

mstoykov approved these changes Sep 4, 2020

View reviewed changes

imiric merged commit feb5056 into master Sep 4, 2020

imiric deleted the fix/1474-name-tag branch September 4, 2020 13:07

na-- added this to the v0.28.0 milestone Sep 4, 2020

imiric mentioned this pull request Sep 16, 2020

Fix sending empty metric tags for failed requests #1633

Merged

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Fix wrong name tag for HTTP metrics from redirects #1570

Fix wrong name tag for HTTP metrics from redirects #1570

imiric commented Jul 23, 2020 •

edited

Loading

codecov-commenter commented Jul 23, 2020 •

edited

Loading

na-- commented Jul 23, 2020

imiric commented Jul 23, 2020

na-- commented Jul 23, 2020

imiric commented Jul 23, 2020

na-- Jul 24, 2020

na-- Jul 24, 2020

imiric Jul 24, 2020

na-- Jul 24, 2020

imiric Jul 24, 2020

mstoykov left a comment

mstoykov Jul 24, 2020

mstoykov Jul 27, 2020

na-- Jul 27, 2020

mstoykov Jul 27, 2020

na-- Jul 27, 2020

imiric Jul 27, 2020

imiric Sep 4, 2020

mstoykov Jul 27, 2020

imiric Jul 27, 2020

mstoykov left a comment •

edited

Loading

mstoykov Sep 4, 2020

imiric Sep 4, 2020

na-- commented Sep 4, 2020

na-- left a comment

mstoykov Sep 4, 2020

imiric Sep 4, 2020

mstoykov Sep 4, 2020

na-- left a comment

imiric commented Sep 4, 2020

mstoykov left a comment

Fix wrong name tag for HTTP metrics from redirects #1570

Fix wrong name tag for HTTP metrics from redirects #1570

Conversation

imiric commented Jul 23, 2020 • edited Loading

codecov-commenter commented Jul 23, 2020 • edited Loading

Codecov Report

na-- commented Jul 23, 2020

imiric commented Jul 23, 2020

na-- commented Jul 23, 2020

imiric commented Jul 23, 2020

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

mstoykov left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

mstoykov left a comment • edited Loading

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

na-- commented Sep 4, 2020

na-- left a comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

na-- left a comment

Choose a reason for hiding this comment

imiric commented Sep 4, 2020

mstoykov left a comment

Choose a reason for hiding this comment

imiric commented Jul 23, 2020 •

edited

Loading

codecov-commenter commented Jul 23, 2020 •

edited

Loading

mstoykov left a comment •

edited

Loading