1826607210

Committed 20 May 2025 09:32AM UTC coverage: 65.859% (-0.002%) from 65.861%

Build # 1826607210

Build Type

push

gitlab-ci

Committed by

web-flow

Commit Message

Merge pull request #682 from mzedel/chore/casing-alignment

Chore/casing alignment

Run Details

32566 of 49448 relevant lines covered (65.86%)

1.39 hits per line

Source File
Press 'n' to go to next uncovered line, 'b' for previous

93.58

/backend/pkg/accesslog/middleware.go

// Copyright 2024 Northern.tech AS
//
//        Licensed under the Apache License, Version 2.0 (the "License");
//        you may not use this file except in compliance with the License.
//        You may obtain a copy of the License at
//
//            http://www.apache.org/licenses/LICENSE-2.0
//
//        Unless required by applicable law or agreed to in writing, software
//        distributed under the License is distributed on an "AS IS" BASIS,
//        WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
//        See the License for the specific language governing permissions and
//        limitations under the License.
package accesslog

import (
        "context"
        "errors"
        "fmt"
        "net"
        "net/http"
        "os"
        "path"
        "runtime"
        "strconv"
        "strings"
        "time"

        "github.com/ant0ine/go-json-rest/rest"
        "github.com/sirupsen/logrus"

        "github.com/mendersoftware/mender-server/pkg/netutils"
        "github.com/mendersoftware/mender-server/pkg/requestlog"
)

const (
        StatusClientClosedConnection = 499

        // nolint:lll
        DefaultLogFormat = "%t %S\033[0m \033[36;1m%Dμs\033[0m \"%r\" \033[1;30m%u \"%{User-Agent}i\"\033[0m"
        SimpleLogFormat  = "%s %Dμs %r %u %{User-Agent}i"

        envProxyDepth = "ACCESSLOG_PROXY_DEPTH"
)

// AccesLogMiddleware uses logger from requestlog and adds a fixed set
// of fields to every accesslog records.
type AccessLogMiddleware struct {
        // Format is not used but kept for historical use.
        // FIXME(QA-673): Remove unused attributes and properties from package.
        Format AccessLogFormat // nolint:unused

        ClientIPHook func(req *http.Request) net.IP
        DisableLog   func(statusCode int, r *rest.Request) bool

        recorder *rest.RecorderMiddleware
}

func getClientIPFromEnv() func(r *http.Request) net.IP {
        if proxyDepthEnv, ok := os.LookupEnv(envProxyDepth); ok {
                proxyDepth, err := strconv.ParseUint(proxyDepthEnv, 10, 8)
                if err == nil {
                        return func(r *http.Request) net.IP {
                                return netutils.GetIPFromXFFDepth(r, int(proxyDepth))
                        }
                }
        }
        return nil
}

const MaxTraceback = 32

func collectTrace() string {
        var (
                trace     [MaxTraceback]uintptr
                traceback strings.Builder
        )
        // Skip 4
        // = accesslog.LogFunc
        // + accesslog.collectTrace
        // + runtime.Callers
        // + runtime.gopanic
        n := runtime.Callers(4, trace[:])
        frames := runtime.CallersFrames(trace[:n])
        for frame, more := frames.Next(); frame.PC != 0 &&
                n >= 0; frame, more = frames.Next() {
                funcName := frame.Function
                if funcName == "" {
                        fmt.Fprint(&traceback, "???\n")
                } else {
                        fmt.Fprintf(&traceback, "%s@%s:%d",
                                frame.Function,
                                path.Base(frame.File),
                                frame.Line,
                        )
                }
                if more {
                        fmt.Fprintln(&traceback)
                }
                n--
        }
        return traceback.String()
}

func (mw *AccessLogMiddleware) LogFunc(
        ctx context.Context, startTime time.Time,
        w rest.ResponseWriter, r *rest.Request) {
        fields := logrus.Fields{
                "type": r.Proto,
                "ts": startTime.
                        Truncate(time.Millisecond).
                        Format(time.RFC3339Nano),
                "method":    r.Method,
                "path":      r.URL.Path,
                "useragent": r.UserAgent(),
                "qs":        r.URL.RawQuery,
        }
        if mw.ClientIPHook != nil {
                fields["clientip"] = mw.ClientIPHook(r.Request)
        }
        lc := fromContext(ctx)
        if lc != nil {
                lc.addFields(fields)
        }
        statusCode, _ := r.Env["STATUS_CODE"].(int)
        select {
        case <-ctx.Done():
                if errors.Is(ctx.Err(), context.Canceled) {
                        statusCode = StatusClientClosedConnection
                }
        default:
        }

        if panic := recover(); panic != nil {
                trace := collectTrace()
                fields["panic"] = panic
                fields["trace"] = trace
                // Wrap in recorder middleware to make sure the response is recorded
                mw.recorder.MiddlewareFunc(func(w rest.ResponseWriter, r *rest.Request) {
                        rest.Error(w, "Internal Server Error", http.StatusInternalServerError)
                })(w, r)
                statusCode = http.StatusInternalServerError
        } else if mw.DisableLog != nil && mw.DisableLog(statusCode, r) {
                return
        }
        rspTime := time.Since(startTime)
        // We do not need more than 3 digit fraction
        if rspTime > time.Second {
                rspTime = rspTime.Round(time.Millisecond)
        } else if rspTime > time.Millisecond {
                rspTime = rspTime.Round(time.Microsecond)
        }
        fields["responsetime"] = rspTime.String()
        fields["byteswritten"], _ = r.Env["BYTES_WRITTEN"].(int64)
        fields["status"] = statusCode

        logger := requestlog.GetRequestLogger(r)
        var level logrus.Level = logrus.InfoLevel
        if statusCode >= 500 {
                level = logrus.ErrorLevel
        } else if statusCode >= 300 {
                level = logrus.WarnLevel
        }
        logger.WithFields(fields).
                Log(level)
}

// MiddlewareFunc makes AccessLogMiddleware implement the Middleware interface.
func (mw *AccessLogMiddleware) MiddlewareFunc(h rest.HandlerFunc) rest.HandlerFunc {
        if mw.ClientIPHook == nil {
                // If not set, try get it from env
                mw.ClientIPHook = getClientIPFromEnv()
        }

        // This middleware depends on RecorderMiddleware to work
        mw.recorder = new(rest.RecorderMiddleware)
        return func(w rest.ResponseWriter, r *rest.Request) {
                ctx := r.Request.Context()
                startTime := time.Now()
                ctx = withContext(ctx, &logContext{maxErrors: DefaultMaxErrors})
                r.Request = r.Request.WithContext(ctx)
                defer mw.LogFunc(ctx, startTime, w, r)
                // call the handler inside recorder context
                mw.recorder.MiddlewareFunc(h)(w, r)
        }
}

1	// Copyright 2024 Northern.tech AS
2	//
3	// Licensed under the Apache License, Version 2.0 (the "License");
4	// you may not use this file except in compliance with the License.
5	// You may obtain a copy of the License at
6	//
7	// http://www.apache.org/licenses/LICENSE-2.0
8	//
9	// Unless required by applicable law or agreed to in writing, software
10	// distributed under the License is distributed on an "AS IS" BASIS,
11	// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
12	// See the License for the specific language governing permissions and
13	// limitations under the License.
14	package accesslog
15
16	import (
17	"context"
18	"errors"
19	"fmt"
20	"net"
21	"net/http"
22	"os"
23	"path"
24	"runtime"
25	"strconv"
26	"strings"
27	"time"
28
29	"github.com/ant0ine/go-json-rest/rest"
30	"github.com/sirupsen/logrus"
31
32	"github.com/mendersoftware/mender-server/pkg/netutils"
33	"github.com/mendersoftware/mender-server/pkg/requestlog"
34	)
35
36	const (
37	StatusClientClosedConnection = 499
38
39	// nolint:lll
40	DefaultLogFormat = "%t %S\033[0m \033[36;1m%Dμs\033[0m \"%r\" \033[1;30m%u \"%{User-Agent}i\"\033[0m"
41	SimpleLogFormat = "%s %Dμs %r %u %{User-Agent}i"
42
43	envProxyDepth = "ACCESSLOG_PROXY_DEPTH"
44	)
45
46	// AccesLogMiddleware uses logger from requestlog and adds a fixed set
47	// of fields to every accesslog records.
48	type AccessLogMiddleware struct {
49	// Format is not used but kept for historical use.
50	// FIXME(QA-673): Remove unused attributes and properties from package.
51	Format AccessLogFormat // nolint:unused
52
53	ClientIPHook func(req *http.Request) net.IP
54	DisableLog func(statusCode int, r *rest.Request) bool
55
56	recorder *rest.RecorderMiddleware
57	}
58
59	func getClientIPFromEnv() func(r *http.Request) net.IP {	9✔
60	if proxyDepthEnv, ok := os.LookupEnv(envProxyDepth); ok {	9✔
61	proxyDepth, err := strconv.ParseUint(proxyDepthEnv, 10, 8)	×
62	if err == nil {	×
63	return func(r *http.Request) net.IP {	×
64	return netutils.GetIPFromXFFDepth(r, int(proxyDepth))	×
65	}	×
66	}
67	}
68	return nil	9✔
69	}
70
71	const MaxTraceback = 32
72
73	func collectTrace() string {	1✔
74	var (	1✔
75	trace [MaxTraceback]uintptr	1✔
76	traceback strings.Builder	1✔
77	)	1✔
78	// Skip 4	1✔
79	// = accesslog.LogFunc	1✔
80	// + accesslog.collectTrace	1✔
81	// + runtime.Callers	1✔
82	// + runtime.gopanic	1✔
83	n := runtime.Callers(4, trace[:])	1✔
84	frames := runtime.CallersFrames(trace[:n])	1✔
85	for frame, more := frames.Next(); frame.PC != 0 &&	1✔
86	n >= 0; frame, more = frames.Next() {	2✔
87	funcName := frame.Function	1✔
88	if funcName == "" {	1✔
89	fmt.Fprint(&traceback, "???\n")	×
90	} else {	1✔
91	fmt.Fprintf(&traceback, "%s@%s:%d",	1✔
92	frame.Function,	1✔
93	path.Base(frame.File),	1✔
94	frame.Line,	1✔
95	)	1✔
96	}	1✔
97	if more {	2✔
98	fmt.Fprintln(&traceback)	1✔
99	}	1✔
100	n--	1✔
101	}
102	return traceback.String()	1✔
103	}
104
105	func (mw *AccessLogMiddleware) LogFunc(
106	ctx context.Context, startTime time.Time,
107	w rest.ResponseWriter, r *rest.Request) {	6✔
108	fields := logrus.Fields{	6✔
109	"type": r.Proto,	6✔
110	"ts": startTime.	6✔
111	Truncate(time.Millisecond).	6✔
112	Format(time.RFC3339Nano),	6✔
113	"method": r.Method,	6✔
114	"path": r.URL.Path,	6✔
115	"useragent": r.UserAgent(),	6✔
116	"qs": r.URL.RawQuery,	6✔
117	}	6✔
118	if mw.ClientIPHook != nil {	7✔
119	fields["clientip"] = mw.ClientIPHook(r.Request)	1✔
120	}	1✔
121	lc := fromContext(ctx)	6✔
122	if lc != nil {	12✔
123	lc.addFields(fields)	6✔
124	}	6✔
125	statusCode, _ := r.Env["STATUS_CODE"].(int)	6✔
126	select {	6✔
127	case <-ctx.Done():	1✔
128	if errors.Is(ctx.Err(), context.Canceled) {	2✔
129	statusCode = StatusClientClosedConnection	1✔
130	}	1✔
131	default:	6✔
132	}
133
134	if panic := recover(); panic != nil {	7✔
135	trace := collectTrace()	1✔
136	fields["panic"] = panic	1✔
137	fields["trace"] = trace	1✔
138	// Wrap in recorder middleware to make sure the response is recorded	1✔
139	mw.recorder.MiddlewareFunc(func(w rest.ResponseWriter, r *rest.Request) {	2✔
140	rest.Error(w, "Internal Server Error", http.StatusInternalServerError)	1✔
141	})(w, r)	1✔
142	statusCode = http.StatusInternalServerError	1✔
143	} else if mw.DisableLog != nil && mw.DisableLog(statusCode, r) {	8✔
144	return	2✔
145	}	2✔
146	rspTime := time.Since(startTime)	6✔
147	// We do not need more than 3 digit fraction	6✔
148	if rspTime > time.Second {	6✔
149	rspTime = rspTime.Round(time.Millisecond)	×
150	} else if rspTime > time.Millisecond {	11✔
151	rspTime = rspTime.Round(time.Microsecond)	5✔
152	}	5✔
153	fields["responsetime"] = rspTime.String()	6✔
154	fields["byteswritten"], _ = r.Env["BYTES_WRITTEN"].(int64)	6✔
155	fields["status"] = statusCode	6✔
156		6✔
157	logger := requestlog.GetRequestLogger(r)	6✔
158	var level logrus.Level = logrus.InfoLevel	6✔
159	if statusCode >= 500 {	9✔
160	level = logrus.ErrorLevel	3✔
161	} else if statusCode >= 300 {	15✔
162	level = logrus.WarnLevel	6✔
163	}	6✔
164	logger.WithFields(fields).	6✔
165	Log(level)	6✔
166	}
167
168	// MiddlewareFunc makes AccessLogMiddleware implement the Middleware interface.
169	func (mw *AccessLogMiddleware) MiddlewareFunc(h rest.HandlerFunc) rest.HandlerFunc {	6✔
170	if mw.ClientIPHook == nil {	11✔
171	// If not set, try get it from env	5✔
172	mw.ClientIPHook = getClientIPFromEnv()	5✔
173	}	5✔
174
175	// This middleware depends on RecorderMiddleware to work
176	mw.recorder = new(rest.RecorderMiddleware)	6✔
177	return func(w rest.ResponseWriter, r *rest.Request) {	12✔
178	ctx := r.Request.Context()	6✔
179	startTime := time.Now()	6✔
180	ctx = withContext(ctx, &logContext{maxErrors: DefaultMaxErrors})	6✔
181	r.Request = r.Request.WithContext(ctx)	6✔
182	defer mw.LogFunc(ctx, startTime, w, r)	6✔
183	// call the handler inside recorder context	6✔
184	mw.recorder.MiddlewareFunc(h)(w, r)	6✔
185	}	6✔
186	}

mendersoftware / mender-server / 1826607210

Source File Press 'n' to go to next uncovered line, 'b' for previous

Source File
Press 'n' to go to next uncovered line, 'b' for previous