util/log: add http log sink

[rauchenstein]

Release note (cli change): Added a new HTTP sink to the logging system.
This can be configured similarly to other log sinks with the new 'http-servers'
and 'http-defaults' sections of the logging config passed via the "--log" or
"--log-config-file" command line flags.

[cockroach-teamcity]

This change is 

[knz]

This looks reasonably good. Thanks for sending it!

what was your idea about using the "context-based" requests?

Reviewed 3 of 8 files at r1, 5 of 5 files at r2.
Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @rauchenstein)

---

docs/generated/logsinks.md, line 181 at r2 (raw file):

as requests to an HTTP server.

The configuration key under the `sinks` key in teh YAML

teh -> the

---

docs/generated/logsinks.md, line 218 at r2 (raw file):

|--|--|
| `channels` | the list of logging channels that use this sink. See the [channel selection configuration](#channel-format) section for details.  |
| `http-defaults` |  |

maybe some description here would help

---

pkg/util/log/flags.go, line 126 at r2 (raw file):

	defer func() {
		if err != nil {
			cleanupFn()

Can you double check the Go semantics here: at which point in the control flow is the value of cleanupFn (a function pointer) taken into the closure?

The reason why I originally chose the way this was written is that cleanupFn is assigned different things throughout the execution of the code below. But maybe that wasn't necessary and what you wrote is correct. I'd just like an explanation in a comment.

---

pkg/util/log/http_sink_test.go, line 42 at r2 (raw file):

		buf := make([]byte, 5000)
		r.Body.Read(buf)
		bodyCh <- string(buf)

you will need a select here to ensure that the termination of testBase due to some other error (e.g. timeout) does not keep this goroutine blocked on writing on this channel.

something like this:

cancel := make(chan struct{})
defer func() { close(cancel) }()

handler := func ... {
    ...
    select {
       case bodyCh <- string(buf):
       case <-cancel:
   }
}

---

pkg/util/log/http_sink_test.go, line 51 at r2 (raw file):

			t.Fatal(err)
		}
		port := strings.Split(l.Addr().String(), ":")[1]

consider netutil.SplitHostPort() instead.

---

pkg/util/log/http_sink_test.go, line 57 at r2 (raw file):

			err := s.Serve(l)
			if err != http.ErrServerClosed {
				serverErrCh <- err

ditto, avoid blocking on this write if the test is exiting prematurely

---

pkg/util/log/http_sink_test.go, line 126 at r2 (raw file):

// Test cases:
// No timeout -- ensure correct behavior.
// Small timeout -- ensure timeout works.

missing new line at end of file

also I think you can remove this comment.

---

pkg/util/log/logconfig/config.go, line 473 at r2 (raw file):

	Channels ChannelList `yaml:",omitempty,flow"`

	HTTPDefaults `yaml:",inline"`

You'll need to modify the doc generator to inline the fields/documentation for this.

---

pkg/util/log/logconfig/validate.go, line 112 at r2 (raw file):

			c.Sinks.HTTPServers[sinkName] = fc
		}
		// fc.serverName = serverName

why don't you need this?

[rauchenstein]

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @knz and @rauchenstein)

---

pkg/util/log/flags.go, line 126 at r2 (raw file):

Previously, knz (kena) wrote…

Can you double check the Go semantics here: at which point in the control flow is the value of cleanupFn (a function pointer) taken into the closure?

The reason why I originally chose the way this was written is that cleanupFn is assigned different things throughout the execution of the code below. But maybe that wasn't necessary and what you wrote is correct. I'd just like an explanation in a comment.

cleanupFn is resolved when the closure runs.

func main() {
	fn := func(){ fmt.Println("one") }
	defer func(){ fn() }()
	fn = func(){ fmt.Println("two") }	
}

...prints "two" while just defer fn() would evaluate the value of fn at the defer site and print "one".

---

pkg/util/log/http_sink_test.go, line 51 at r2 (raw file):

Previously, knz (kena) wrote…

consider netutil.SplitHostPort() instead.

I did. This avoided a circular dependency, since netutil evidently does some logging.

[knz]

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @rauchenstein)

---

pkg/util/log/flags.go, line 126 at r2 (raw file):

Previously, rauchenstein wrote…

cleanupFn is resolved when the closure runs.

func main() {
	fn := func(){ fmt.Println("one") }
	defer func(){ fn() }()
	fn = func(){ fmt.Println("two") }	
}

...prints "two" while just defer fn() would evaluate the value of fn at the defer site and print "one".

TIL - Worth outlining in a comment then.

---

pkg/util/log/http_sink_test.go, line 51 at r2 (raw file):

Previously, rauchenstein wrote…

I did. This avoided a circular dependency, since netutil evidently does some logging.

TIL. Maybe explain this in a comment then.

[rauchenstein]

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @knz and @rauchenstein)

---

docs/generated/logsinks.md, line 181 at r2 (raw file):

Previously, knz (kena) wrote…

teh -> the

Done.

---

docs/generated/logsinks.md, line 218 at r2 (raw file):

Previously, knz (kena) wrote…

maybe some description here would help

Done. Fixing the linter's preference of HTTPDefaults over HttpDefaults actually broke this. Regex assumed one capitalized word before "Defaults." Made the regex more general and fixed the camel-casing logic to support "words" in all CAPS.

---

pkg/util/log/flags.go, line 126 at r2 (raw file):

Previously, knz (kena) wrote…

TIL - Worth outlining in a comment then.

Done.

---

pkg/util/log/http_sink_test.go, line 42 at r2 (raw file):

Previously, knz (kena) wrote…

you will need a select here to ensure that the termination of testBase due to some other error (e.g. timeout) does not keep this goroutine blocked on writing on this channel.

something like this:

cancel := make(chan struct{})
defer func() { close(cancel) }()

handler := func ... {
    ...
    select {
       case bodyCh <- string(buf):
       case <-cancel:
   }
}

Done.

---

pkg/util/log/http_sink_test.go, line 51 at r2 (raw file):

Previously, knz (kena) wrote…

TIL. Maybe explain this in a comment then.

Done.

---

pkg/util/log/http_sink_test.go, line 57 at r2 (raw file):

Previously, knz (kena) wrote…

ditto, avoid blocking on this write if the test is exiting prematurely

Done.

---

pkg/util/log/logconfig/config.go, line 473 at r2 (raw file):

Previously, knz (kena) wrote…

You'll need to modify the doc generator to inline the fields/documentation for this.

Done.

---

pkg/util/log/logconfig/validate.go, line 112 at r2 (raw file):

Previously, knz (kena) wrote…

why don't you need this?

I had to approach this more as "why do the other sinks need this?" because other than FileSink (for which the sink name affects the file names), the sink name doesn't actually affect functionality. So I looked into what FluentSink does with it and it appears to only be used for the UML diagram produced by logconfig/export.go. To some degree, this suggests that using a map instead of a list in the logconfig was probably not the best design (but that would be a breaking change at this point).

But that investigation led me to finding export.go as another place that changes are needed.

[rauchenstein]

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @knz and @rauchenstein)

---

docs/generated/logsinks.md, line 181 at r2 (raw file):

Previously, rauchenstein wrote…

Done.

Wait, not done? Let me look again.

[rauchenstein]

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @knz and @rauchenstein)

---

docs/generated/logsinks.md, line 181 at r2 (raw file):

Previously, rauchenstein wrote…

Wait, not done? Let me look again.

Done.

[knz]

Ok this mostly looks good now.

I'd like you to spell out the followup work with contexts in a github issue and refer to it from this PR's description, and possibly as TODOs in the code in relevant locations.

Additionally, I'd like you to explain what your view is on the configuration, see my comment below.

Reviewed 6 of 6 files at r3.
Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @rauchenstein)

---

pkg/util/log/http_sink_test.go, line 57 at r3 (raw file):

			t.Fatal(err)
		}
		// netutil.SplitHostPort would cause a circular dependency, so just do a string split

You can use addr.SplitHostPort now and avoid a circular dependency.

---

pkg/util/log/logconfig/validate.go, line 112 at r2 (raw file):

it appears to only be used for the UML diagram produced by logconfig/export.go. To some degree, this suggests that using a map instead of a list in the logconfig was probably not the best design

Yes granted, but the diagram is valuable.
My position at this point is that regardless of the flaws in the design, we probably want consistent behavior between fluent and http sinks.

that investigation led me to finding export.go as another place that changes are needed.

What changes?

[rauchenstein]

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @knz and @rauchenstein)

---

pkg/util/log/http_sink_test.go, line 57 at r3 (raw file):

Previously, knz (kena) wrote…

You can use addr.SplitHostPort now and avoid a circular dependency.

Done.

---

pkg/util/log/logconfig/validate.go, line 112 at r2 (raw file):

Previously, knz (kena) wrote…

it appears to only be used for the UML diagram produced by logconfig/export.go. To some degree, this suggests that using a map instead of a list in the logconfig was probably not the best design

Yes granted, but the diagram is valuable.
My position at this point is that regardless of the flaws in the design, we probably want consistent behavior between fluent and http sinks.

that investigation led me to finding export.go as another place that changes are needed.

What changes?

Presumably we want http sinks to appear in the diagram.

[knz]

Reviewed 6 of 6 files at r4.
Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @rauchenstein)

---

pkg/util/log/http_sink.go, line 1 at r4 (raw file):

// Copyright 2020 The Cockroach Authors.

2021

---

pkg/util/log/http_sink_test.go, line 126 at r2 (raw file):

Previously, knz (kena) wrote…

missing new line at end of file

also I think you can remove this comment.

This comment is still out of place.

---

pkg/util/log/http_sink_test.go, line 1 at r4 (raw file):

// Copyright 2020 The Cockroach Authors.

2021

---

pkg/util/log/http_sink_test.go, line 29 at r4 (raw file):

)

// TODO: HTTP server needs bound to context -- still need to figure out the right context.

This comment is still out of place.

[rauchenstein]

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @knz)

---

pkg/util/log/http_sink.go, line 1 at r4 (raw file):

Previously, knz (kena) wrote…

2021

Done.

---

pkg/util/log/http_sink_test.go, line 126 at r2 (raw file):

Previously, knz (kena) wrote…

This comment is still out of place.

Done.

---

pkg/util/log/http_sink_test.go, line 1 at r4 (raw file):

Previously, knz (kena) wrote…

2021

Done.

---

pkg/util/log/http_sink_test.go, line 29 at r4 (raw file):

Previously, knz (kena) wrote…

This comment is still out of place.

Done.

[rauchenstein]

Having trouble figuring out this leaking goroutine issue. (See GitHub CI test history. I've been having to rely on CI, since I've never had this issue locally.) Initially, I thought allowing mechanisms like cancelCh that allow goroutines to complete would be sufficient. @itsbilal helped by pointing out that an explicit join using a WaitGroup or ServerClosedCh would be necessary to be sure the goroutines not only terminate, but do so by the time the test checks. But neither of those seem to have made a difference -- there's still a goroutine leak.

[knz]

leakcheck waits for a little bit for lingering goroutines to terminate on their own, so we're not anxious to use wait groups. I'll have a look

[knz]

thank you! 💯

[rauchenstein]

bors r=knz

[craig]

Build succeeded:

• GitHub CI (Cockroach)