logging: add support for request ID

[mmatczuk]

Requirements:

• All log lines related to processing of a request should have request ID
• Request ID should be read from X-Request-ID header
• If missing it should be generated

[mmatczuk]

Goproxy uses session ctx.Session & 0xFF as identifier we should probably adapt it

func (ctx *ProxyCtx) printf(msg string, argv ...interface{}) {
	ctx.Proxy.Logger.Printf("[%03d] "+msg+"\n", append([]interface{}{ctx.Session & 0xFF}, argv...)...)
}

example output

2022/09/26 14:01:10 [local] DEBUG: [001] INFO: Copying response to client 200 OK [200]
2022/09/26 14:01:10 [local] DEBUG: [001] INFO: Copied 4 bytes to client error=<nil>

If X-Request-ID is present it should be logged to associate the ID with Session ID.

[mmatczuk]

There are exported logging functions

// Logf prints a message to the proxy's log. Should be used in a ProxyHttpServer's filter
// This message will be printed only if the Verbose field of the ProxyHttpServer is set to true
//
//	proxy.OnRequest().DoFunc(func(r *http.Request,ctx *goproxy.ProxyCtx) (*http.Request, *http.Response){
//		nr := atomic.AddInt32(&counter,1)
//		ctx.Printf("So far %d requests",nr)
//		return r, nil
//	})
func (ctx *ProxyCtx) Logf(msg string, argv ...interface{}) {
	if ctx.Proxy.Verbose {
		ctx.printf("INFO: "+msg, argv...)
	}
}

// Warnf prints a message to the proxy's log. Should be used in a ProxyHttpServer's filter
// This message will always be printed.
//
//	proxy.OnRequest().DoFunc(func(r *http.Request,ctx *goproxy.ProxyCtx) (*http.Request, *http.Response){
//		f,err := os.OpenFile(cachedContent)
//		if err != nil {
//			ctx.Warnf("error open file %v: %v",cachedContent,err)
//			return r, nil
//		}
//		return r, nil
//	})
func (ctx *ProxyCtx) Warnf(msg string, argv ...interface{}) {
	ctx.printf("WARN: "+msg, argv...)
}

[mmatczuk]

I think its not needed since we log request with response.

[mmatczuk]

Reopening the issue. This mainly requires changes in Marian logging, when sth goes wrong, we want to know which issue caused the error.

[mmatczuk]

Once we have the context the in the logs the implementation should be in Proxy::readRequest (and a parallel implementation in handler).

To request context.Context add requestID value

• if X-Request-ID header is set use its value
• otherwise use Martian context ID

[Choraden]

As long as CONNECT request does not forward X-Forwarded-Headers we are not able to support reusing request id.

[mmatczuk]

@Choraden we have RequestIDHeader in martian and as far as I can tell it's never used.

[Choraden]

It looks like this functionality was removed in 56352ab4.

We need to decide whether we want to fix it or completely remove it.

[mmatczuk]

I'll fix it.

[mmatczuk]

It can be added to out connect implementation.

[mmatczuk]

This has already been implemented.