Neat! I left some comments from my initial read through.

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

pkg/util/log/intercept.go, line 59 at r1 (raw file):

type InterceptMessageFn func(message []byte)

// interceptorsPtr stores a pointer to the list of currently active interceptors.

Should this comment be on the line below?

pkg/util/log/intercept.go, line 72 at r1 (raw file):

// interceptorID returns the ID for the specified interceptor.
func interceptorID(interceptor *InterceptMessageFn) InterceptorID {
	return InterceptorID(unsafe.Pointer(interceptor))

I will likely expose some ignorance of Go internals here, but if I'm reading the documentation right, comparing the uintptr's works today for heap-allocated objects but isn't guaranteed by the language spec (and I think wouldn't work for stack-allocated objects: https://play.golang.org/p/0_f3MAp96JL).

Not recommending a change, just talking through my understanding. I believe this will work on our current version of Go.

pkg/util/log/intercept.go, line 99 at r1 (raw file):

	}
	if yank == -1 {
		panic("cannot remove interceptor")

Might be worth a comment on why we want this to be a hard panic vs a no-op (perhaps just returning l)?

pkg/util/log/intercept.go, line 129 at r1 (raw file):

			newInterceptorsPtr = &newInterceptors
		}
		if atomic.CompareAndSwapPointer(&interceptorsPtr, addr, unsafe.Pointer(newInterceptorsPtr)) {

Question: Would it be worth a comment on why a mutex wouldn't suffice here?

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

pkg/util/log/intercept.go, line 72 at r1 (raw file):

It's unlikely you're ignorant in Go -- I'd say I am... I was looking for weak_ptr in Go -- that kinda shows the level of ignorance I have :)

So, this particular code, I was going back and forth, at least 4 or 5 times...
There are few things at play here:

1. (and that's the most important) Interceptors should have "id" associated with them so that
   I have tried using a pointer itself as an ID, but found it not very satisfying.
2. To support add/remove as a pointer value, I have to pass an implementation of a (now deleted) LogMessageInterceptor interface. But interface comparisons are tricky. In particular, you could have different
   interceptors, but as long as their underlying implementation is the same (i.e. empty struct), then interface value comparison would not work.
3. I felt (not strongly) that having an interface might be an overkill, where a function would work (note, you cannot compare functions).

So, taking these together, i'm back to my original desire: I need a unique ID for an interceptor.
One way: just maybe use time, or some such, and redo things in a loop when adding interceptor. And maybe, that's a good way to go.

The above works (and maybe it's too smart for its own good) because to add an interceptor, you pass in an InterceptMessageFn (note, not a pointer) by value to the AddInterceptor method. Thereafter, I take the address of that stack allocated parameter, and If I understand correctly, that parameter "escapes to heap" (because I will save it inside my interceptorList). As long as that object is in use, nothing should be stored at that memory address -- so I think taking uintptr address of that value is okay.

But then, maybe I'm entirely wrong...

pkg/util/log/intercept.go, line 129 at r1 (raw file):

Having mutex means you have to lock to check if you have interceptors. We don't want to lock every time you log.

I wish to review this more in depth but note that I am on PTO at this moment. So please give me some time to process this.

My initial remark though, in response to the ongoing conversation in the review thread, is that you made this overly complicated. IMHO you could have written type InterceptorID *interceptorSink and that would have made your API simpler. We'll discuss more when I have a chance to scrutinize this further.

Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @miretskiy and @stevendanna)

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

pkg/util/log/intercept.go, line 59 at r1 (raw file):

obsolete.

pkg/util/log/intercept.go, line 72 at r1 (raw file):

Alright -- I think it was trying to be too fancy, as pointed out by @stevendanna and @knz
Reworked to something which I think is A LOT simpler.

pkg/util/log/intercept.go, line 99 at r1 (raw file):

Obsolete.

pkg/util/log/intercept.go, line 129 at r1 (raw file):

This is now obsolete.

Ok I have given this PR a deeper look.

The main contention I have with the current approach is that it incurs the cost of an extra sink on all channels even when there is no interceptor currently defined. This is surprising and arguably undesirable.

In my opinion, we should add a sink only when a test requires interception and remove it when the interception is not needed any more. We should also do 1 interception per sink. So if there are 10 interceptors registered, that would be 10 different sinks.

Meanwhile, I would also like to point out that we do not need to intercept all channels.
The tests that need an interceptor only need to intercept 1 channel.
The logspy feature only needs to intercept the DEV channel.

So the intercept API should take a channel argument and only install an interceptor sink for that channel.

For example I am thinking of the following API:

package log

// RegisterInterceptor registers the given interceptFn on the specificed channel.
// The log entries are formatted using the format specified in desiredFormat
// before they are passed to the intercept fn.
// The interceptor is set up as a sink with no severity filter, and with redaction markers enabled.
//
// The caller is responsible for calling the returned cleanup fn when the interceptor is
// not needed any more, to de-register the sink.
func RegisterInterceptor(ch channels.Channel,  desiredFormat string, interceptFn func([]byte))  (cleanup func())

Reviewed 2 of 4 files at r1, 1 of 3 files at r2.
Reviewable status: complete! 0 of 0 LGTMs obtained (waiting on @knz and @stevendanna)

"The main contention I have with the current approach is that it incurs the cost of an extra sink on all channels even when there is no interceptor currently defined. This is surprising and arguably undesirable."

I'm not sure the cost is larger in any meaningful way than it is today. We check for atomic variable when calling outputLogEntry; as opposed to this implementation, which, when iterating over configured sinks checks that interceptor is not active (by loading atomic variable) -- are you concerned over the cost of 1 more sink in the loop?

I like the suggestion re adding sink per channel (which makes above moot, btw). Before I do that, I wanted to ask your opinion on the implementation details... loggerT contains the list of sinkInfos -- and presumably, if the intercept is active, that's where I would need to add interceptor sink. However, the loggerT is initialized at the startup and never modified.
I don't love the idea of adding any locks there.

I could use the loggingT rmu lock, which protects channel->*loggerT map, but, the comment on that lock seems to
imply it's a mis-design and should be removed.

Finally, I could change loggerT itself to have an atomic ptr instead of []sinkInfos, and use atomic compare/swap when I want to add/remove interceptor sink(s).

Finally, while I can certainly use func([]byte) as interceptor, and I did so in the earlier incarnations, is it much better
vs using an interface? Interface could be extended -- for example to support redaction for example.

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

@knz
Just pushed new version which uses atomics to manage sink infos w/out locks.
A bit more complex than before.

Take a look -- let me know what you think. I'm not sure about the Config() method I added
to the interceptor and whether it's a good idea.

I'm almost inclined to use default interceptor configuration that will redact by default
(and make LogMessageInterceptor not configurable). On the other hand, maybe there are uses
for non-redacted interceptors. WDYT?

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

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

pkg/util/log/intercept.go, line 72 at r1 (raw file):

Done.

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

pkg/util/log/intercept.go, line 72 at r1 (raw file):

Done.

it would be a great help if vmodule could be specified within a logspy invocation as well

Good idea. Done. (The way you suggested.)

The logspy endpoint is also currently self-documenting (if you call it without parameters, you get one line showing you the parameters)

It shows you a representation of the Go struct, not the HTTP query parameters. I don't think that's a big deal, because...

the link on the debug page in the ui should include all parameters (maybe it already does)

it does.

The commit message could specify how overlapping vmodule requests are handled.

Done:

Note: at most one in-flight HTTP API request is allowed to modify the
vmodule parameter. This maintain the invariant that the
configuration restored at the end of each request is the same as when
the request started.

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

Was just testing this out, the debug page prints:
/debug/logspy?count=[count]&duration=[duration]&grep=[regexp]&vmodule=[vmodule]
I think this should also list &flatten=[bool]

Done.

Also, the actual link is too vanilla: http://td:8080/debug/logspy?count=1&duration=10s&grep=.
Could all the parameters be populated in the link? That way, it's easier to click through and adjust rather than always having to remember the description.

Done.

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