log authentication errors of API, metrics, pprof (#4641) (#5015)

internal/api/api.go

@@ -258,6 +258,8 @@ func (a *API) middlewareAuth(ctx *gin.Context) {
 			return
 		}
 
+		a.Log(logger.Info, "connection %v failed to authenticate: %v", httpp.RemoteAddr(ctx), err.Wrapped)
+
 		// wait some seconds to mitigate brute force attacks
 		<-time.After(auth.PauseAfterError)
 

internal/api/api_test.go

@@ -3,6 +3,7 @@ package api
 import (
 	"bytes"
 	"encoding/json"
+	"fmt"
 	"io"
 	"net/http"
 	"net/url"
@@ -18,9 +19,14 @@ import (
 	"github.com/stretchr/testify/require"
 )
 
-type testParent struct{}
+type testParent struct {
+	log func(_ logger.Level, _ string, _ ...interface{})
+}
 
-func (testParent) Log(_ logger.Level, _ string, _ ...interface{}) {
+func (p testParent) Log(l logger.Level, s string, a ...interface{}) {
+	if p.log != nil {
+		p.log(l, s, a...)
+	}
 }
 
 func (testParent) APIConfigSet(_ *conf.Conf) {}
@@ -113,12 +119,21 @@ func TestPreflightRequest(t *testing.T) {
 
 func TestConfigGlobalGet(t *testing.T) {
 	cnf := tempConf(t, "api: yes\n")
+	checked := false
 
 	api := API{
 		Address:     "localhost:9997",
 		ReadTimeout: conf.Duration(10 * time.Second),
 		Conf:        cnf,
-		AuthManager: test.NilAuthManager,
+		AuthManager: &test.AuthManager{
+			AuthenticateImpl: func(req *auth.Request) *auth.Error {
+				require.Equal(t, conf.AuthActionAPI, req.Action)
+				require.Equal(t, "myuser", req.Credentials.User)
+				require.Equal(t, "mypass", req.Credentials.Pass)
+				checked = true
+				return nil
+			},
+		},
 		Parent: &testParent{},
 	}
 	err := api.Initialize()
@@ -130,8 +145,10 @@ func TestConfigGlobalGet(t *testing.T) {
 	hc := &http.Client{Transport: tr}
 
 	var out map[string]interface{}
-	httpRequest(t, hc, http.MethodGet, "http://localhost:9997/v3/config/global/get", nil, &out)
+	httpRequest(t, hc, http.MethodGet, "http://myuser:mypass@localhost:9997/v3/config/global/get", nil, &out)
 	require.Equal(t, true, out["api"])
+
+	require.True(t, checked)
 }
 
 func TestConfigGlobalPatch(t *testing.T) {
@@ -757,3 +774,54 @@ func TestAuthJWKSRefresh(t *testing.T) {
 
 	require.True(t, ok)
 }
+
+func TestAuthError(t *testing.T) {
+	cnf := tempConf(t, "api: yes\n")
+	n := 0
+
+	api := API{
+		Address:     "localhost:9997",
+		ReadTimeout: conf.Duration(10 * time.Second),
+		Conf:        cnf,
+		AuthManager: &test.AuthManager{
+			AuthenticateImpl: func(req *auth.Request) *auth.Error {
+				if req.Credentials.User == "" {
+					return &auth.Error{AskCredentials: true}
+				}
+				return &auth.Error{Wrapped: fmt.Errorf("auth error")}
+			},
+		},
+		Parent: &testParent{
+			log: func(l logger.Level, s string, i ...interface{}) {
+				if l == logger.Info {
+					if n == 1 {
+						require.Regexp(t, "failed to authenticate: auth error$", fmt.Sprintf(s, i...))
+					}
+					n++
+				}
+			},
+		},
+	}
+	err := api.Initialize()
+	require.NoError(t, err)
+	defer api.Close()
+
+	tr := &http.Transport{}
+	defer tr.CloseIdleConnections()
+	hc := &http.Client{Transport: tr}
+
+	res, err := hc.Get("http://localhost:9997/v3/config/global/get")
+	require.NoError(t, err)
+	defer res.Body.Close()
+
+	require.Equal(t, http.StatusUnauthorized, res.StatusCode)
+	require.Equal(t, `Basic realm="mediamtx"`, res.Header.Get("WWW-Authenticate"))
+
+	res, err = hc.Get("http://myuser:mypass@localhost:9997/v3/config/global/get")
+	require.NoError(t, err)
+	defer res.Body.Close()
+
+	require.Equal(t, http.StatusUnauthorized, res.StatusCode)
+
+	require.Equal(t, 2, n)
+}

internal/metrics/metrics.go

@@ -162,6 +162,8 @@ func (m *Metrics) middlewareAuth(ctx *gin.Context) {
 			return
 		}
 
+		m.Log(logger.Info, "connection %v failed to authenticate: %v", httpp.RemoteAddr(ctx), err.Wrapped)
+
 		// wait some seconds to mitigate brute force attacks
 		<-time.After(auth.PauseAfterError)
 

internal/metrics/metrics_test.go

@@ -1,13 +1,16 @@
 package metrics
 
 import (
+	"fmt"
 	"io"
 	"net/http"
 	"testing"
 	"time"
 
+	"github.com/bluenviron/mediamtx/internal/auth"
 	"github.com/bluenviron/mediamtx/internal/conf"
 	"github.com/bluenviron/mediamtx/internal/defs"
+	"github.com/bluenviron/mediamtx/internal/logger"
 	"github.com/bluenviron/mediamtx/internal/test"
 	"github.com/google/uuid"
 	"github.com/stretchr/testify/require"
@@ -224,11 +227,21 @@ func TestPreflightRequest(t *testing.T) {
 }
 
 func TestMetrics(t *testing.T) {
+	checked := false
+
 	m := Metrics{
 		Address:     "localhost:9998",
 		AllowOrigin: "*",
 		ReadTimeout: conf.Duration(10 * time.Second),
-		AuthManager: test.NilAuthManager,
+		AuthManager: &test.AuthManager{
+			AuthenticateImpl: func(req *auth.Request) *auth.Error {
+				require.Equal(t, conf.AuthActionMetrics, req.Action)
+				require.Equal(t, "myuser", req.Credentials.User)
+				require.Equal(t, "mypass", req.Credentials.Pass)
+				checked = true
+				return nil
+			},
+		},
 		Parent: test.NilLogger,
 	}
 	err := m.Initialize()
@@ -247,10 +260,12 @@ func TestMetrics(t *testing.T) {
 	defer tr.CloseIdleConnections()
 	hc := &http.Client{Transport: tr}
 
-	res, err := hc.Get("http://localhost:9998/metrics")
+	res, err := hc.Get("http://myuser:mypass@localhost:9998/metrics")
 	require.NoError(t, err)
 	defer res.Body.Close()
 
+	require.Equal(t, http.StatusOK, res.StatusCode)
+
 	byts, err := io.ReadAll(res.Body)
 	require.NoError(t, err)
 
@@ -342,9 +357,59 @@ func TestMetrics(t *testing.T) {
 			`webrtc_sessions_rtcp_packets_sent{id="f47ac10b-58cc-4372-a567-0e02b2c3d479",`+
 			`path="mypath",remoteAddr="127.0.0.1:3455",state="read"} 456`+"\n",
 		string(byts))
+
+	require.True(t, checked)
 }
 
-func TestMetricsFilter(t *testing.T) {
+func TestAuthError(t *testing.T) {
+	n := 0
+
+	m := Metrics{
+		Address:     "localhost:9998",
+		AllowOrigin: "*",
+		ReadTimeout: conf.Duration(10 * time.Second),
+		AuthManager: &test.AuthManager{
+			AuthenticateImpl: func(req *auth.Request) *auth.Error {
+				if req.Credentials.User == "" {
+					return &auth.Error{AskCredentials: true}
+				}
+				return &auth.Error{Wrapped: fmt.Errorf("auth error")}
+			},
+		},
+		Parent: test.Logger(func(l logger.Level, s string, i ...interface{}) {
+			if l == logger.Info {
+				if n == 1 {
+					require.Regexp(t, "failed to authenticate: auth error$", fmt.Sprintf(s, i...))
+				}
+				n++
+			}
+		}),
+	}
+	err := m.Initialize()
+	require.NoError(t, err)
+	defer m.Close()
+
+	tr := &http.Transport{}
+	defer tr.CloseIdleConnections()
+	hc := &http.Client{Transport: tr}
+
+	res, err := hc.Get("http://localhost:9998/metrics")
+	require.NoError(t, err)
+	defer res.Body.Close()
+
+	require.Equal(t, http.StatusUnauthorized, res.StatusCode)
+	require.Equal(t, `Basic realm="mediamtx"`, res.Header.Get("WWW-Authenticate"))
+
+	res, err = hc.Get("http://myuser:mypass@localhost:9998/metrics")
+	require.NoError(t, err)
+	defer res.Body.Close()
+
+	require.Equal(t, http.StatusUnauthorized, res.StatusCode)
+
+	require.Equal(t, 2, n)
+}
+
+func TestFilter(t *testing.T) {
 	for _, ca := range []string{
 		"path",
 		"hls_muxer",

internal/playback/on_list_test.go

@@ -57,6 +57,8 @@ func TestOnList(t *testing.T) {
 				writeSegment1(t, filepath.Join(dir, "mypath", "2008-11-07_11-22-00-500000.mp4"))
 			}
 
+			checked := false
+
 			s := &Server{
 				Address:     "127.0.0.1:9996",
 				ReadTimeout: conf.Duration(10 * time.Second),
@@ -66,7 +68,15 @@ func TestOnList(t *testing.T) {
 						RecordPath: filepath.Join(dir, "%path/%Y-%m-%d_%H-%M-%S-%f"),
 					},
 				},
-				AuthManager: test.NilAuthManager,
+				AuthManager: &test.AuthManager{
+					AuthenticateImpl: func(req *auth.Request) *auth.Error {
+						require.Equal(t, conf.AuthActionPlayback, req.Action)
+						require.Equal(t, "myuser", req.Credentials.User)
+						require.Equal(t, "mypass", req.Credentials.Pass)
+						checked = true
+						return nil
+					},
+				},
 				Parent: test.NilLogger,
 			}
 			err = s.Initialize()
@@ -174,6 +184,8 @@ func TestOnList(t *testing.T) {
 					},
 				}, out)
 			}
+
+			require.True(t, checked)
 		})
 	}
 }
@@ -321,51 +333,3 @@ func TestOnListCachedDuration(t *testing.T) {
 		},
 	}, out)
 }
-
-func TestOnListAuthError(t *testing.T) {
-	dir, err := os.MkdirTemp("", "mediamtx-playback")
-	require.NoError(t, err)
-	defer os.RemoveAll(dir)
-
-	s := &Server{
-		Address:     "127.0.0.1:9996",
-		ReadTimeout: conf.Duration(10 * time.Second),
-		PathConfs: map[string]*conf.Path{
-			"mypath": {
-				Name:       "mypath",
-				RecordPath: filepath.Join(dir, "%path/%Y-%m-%d_%H-%M-%S-%f"),
-			},
-		},
-		AuthManager: &test.AuthManager{
-			AuthenticateImpl: func(_ *auth.Request) *auth.Error {
-				return &auth.Error{Wrapped: fmt.Errorf("auth error")}
-			},
-			RefreshJWTJWKSImpl: func() {
-			},
-		},
-		Parent: test.NilLogger,
-	}
-	err = s.Initialize()
-	require.NoError(t, err)
-	defer s.Close()
-
-	u, err := url.Parse("http://myuser:mypass@localhost:9996/list")
-	require.NoError(t, err)
-
-	v := url.Values{}
-	v.Set("path", "mypath")
-	u.RawQuery = v.Encode()
-
-	req, err := http.NewRequest(http.MethodGet, u.String(), nil)
-	require.NoError(t, err)
-
-	start := time.Now()
-
-	res, err := http.DefaultClient.Do(req)
-	require.NoError(t, err)
-	defer res.Body.Close()
-
-	require.Greater(t, time.Since(start), 2*time.Second)
-
-	require.Equal(t, http.StatusUnauthorized, res.StatusCode)
-}

internal/playback/server_test.go

@@ -1,12 +1,16 @@
 package playback
 
 import (
+	"fmt"
 	"io"
 	"net/http"
+	"net/url"
 	"testing"
 	"time"
 
+	"github.com/bluenviron/mediamtx/internal/auth"
 	"github.com/bluenviron/mediamtx/internal/conf"
+	"github.com/bluenviron/mediamtx/internal/logger"
 	"github.com/bluenviron/mediamtx/internal/test"
 	"github.com/stretchr/testify/require"
 )
@@ -46,3 +50,70 @@ func TestPreflightRequest(t *testing.T) {
 	require.Equal(t, "Authorization", res.Header.Get("Access-Control-Allow-Headers"))
 	require.Equal(t, byts, []byte{})
 }
+
+func TestAuthError(t *testing.T) {
+	n := 0
+
+	s := &Server{
+		Address:     "127.0.0.1:9996",
+		ReadTimeout: conf.Duration(10 * time.Second),
+		AuthManager: &test.AuthManager{
+			AuthenticateImpl: func(req *auth.Request) *auth.Error {
+				if req.Credentials.User == "" {
+					return &auth.Error{AskCredentials: true}
+				}
+				return &auth.Error{Wrapped: fmt.Errorf("auth error")}
+			},
+		},
+		Parent: test.Logger(func(l logger.Level, s string, i ...interface{}) {
+			if l == logger.Info {
+				if n == 1 {
+					require.Regexp(t, "failed to authenticate: auth error$", fmt.Sprintf(s, i...))
+				}
+				n++
+			}
+		}),
+	}
+	err := s.Initialize()
+	require.NoError(t, err)
+	defer s.Close()
+
+	u, err := url.Parse("http://localhost:9996/list")
+	require.NoError(t, err)
+
+	v := url.Values{}
+	v.Set("path", "mypath")
+	u.RawQuery = v.Encode()
+
+	req, err := http.NewRequest(http.MethodGet, u.String(), nil)
+	require.NoError(t, err)
+
+	res, err := http.DefaultClient.Do(req)
+	require.NoError(t, err)
+	defer res.Body.Close()
+
+	require.Equal(t, http.StatusUnauthorized, res.StatusCode)
+	require.Equal(t, `Basic realm="mediamtx"`, res.Header.Get("WWW-Authenticate"))
+
+	u, err = url.Parse("http://myuser:mypass@localhost:9996/list")
+	require.NoError(t, err)
+
+	v = url.Values{}
+	v.Set("path", "mypath")
+	u.RawQuery = v.Encode()
+
+	req, err = http.NewRequest(http.MethodGet, u.String(), nil)
+	require.NoError(t, err)
+
+	start := time.Now()
+
+	res, err = http.DefaultClient.Do(req)
+	require.NoError(t, err)
+	defer res.Body.Close()
+
+	require.Greater(t, time.Since(start), 2*time.Second)
+
+	require.Equal(t, http.StatusUnauthorized, res.StatusCode)
+
+	require.Equal(t, 2, n)
+}

internal/pprof/pprof.go

@@ -108,6 +108,8 @@ func (pp *PPROF) middlewareAuth(ctx *gin.Context) {
 			return
 		}
 
+		pp.Log(logger.Info, "connection %v failed to authenticate: %v", httpp.RemoteAddr(ctx), err.Wrapped)
+
 		// wait some seconds to mitigate brute force attacks
 		<-time.After(auth.PauseAfterError)
 

internal/pprof/pprof_test.go

@@ -1,12 +1,15 @@
 package pprof
 
 import (
+	"fmt"
 	"io"
 	"net/http"
 	"testing"
 	"time"
 
+	"github.com/bluenviron/mediamtx/internal/auth"
 	"github.com/bluenviron/mediamtx/internal/conf"
+	"github.com/bluenviron/mediamtx/internal/logger"
 	"github.com/bluenviron/mediamtx/internal/test"
 	"github.com/stretchr/testify/require"
 )
@@ -48,11 +51,21 @@ func TestPreflightRequest(t *testing.T) {
 }
 
 func TestPprof(t *testing.T) {
+	checked := false
+
 	s := &PPROF{
 		Address:     "127.0.0.1:9999",
 		AllowOrigin: "*",
 		ReadTimeout: conf.Duration(10 * time.Second),
-		AuthManager: test.NilAuthManager,
+		AuthManager: &test.AuthManager{
+			AuthenticateImpl: func(req *auth.Request) *auth.Error {
+				require.Equal(t, conf.AuthActionPprof, req.Action)
+				require.Equal(t, "myuser", req.Credentials.User)
+				require.Equal(t, "mypass", req.Credentials.Pass)
+				checked = true
+				return nil
+			},
+		},
 		Parent: test.NilLogger,
 	}
 	err := s.Initialize()
@@ -63,6 +76,54 @@ func TestPprof(t *testing.T) {
 	defer tr.CloseIdleConnections()
 	hc := &http.Client{Transport: tr}
 
+	req, err := http.NewRequest(http.MethodGet, "http://myuser:mypass@127.0.0.1:9999/debug/pprof/heap", nil)
+	require.NoError(t, err)
+
+	res, err := hc.Do(req)
+	require.NoError(t, err)
+	defer res.Body.Close()
+
+	require.Equal(t, http.StatusOK, res.StatusCode)
+
+	byts, err := io.ReadAll(res.Body)
+	require.NoError(t, err)
+	require.NotEmpty(t, byts)
+
+	require.True(t, checked)
+}
+
+func TestAuthError(t *testing.T) {
+	n := 0
+
+	s := &PPROF{
+		Address:     "127.0.0.1:9999",
+		AllowOrigin: "*",
+		ReadTimeout: conf.Duration(10 * time.Second),
+		AuthManager: &test.AuthManager{
+			AuthenticateImpl: func(req *auth.Request) *auth.Error {
+				if req.Credentials.User == "" {
+					return &auth.Error{AskCredentials: true}
+				}
+				return &auth.Error{Wrapped: fmt.Errorf("auth error")}
+			},
+		},
+		Parent: test.Logger(func(l logger.Level, s string, i ...interface{}) {
+			if l == logger.Info {
+				if n == 1 {
+					require.Regexp(t, "failed to authenticate: auth error$", fmt.Sprintf(s, i...))
+				}
+				n++
+			}
+		}),
+	}
+	err := s.Initialize()
+	require.NoError(t, err)
+	defer s.Close()
+
+	tr := &http.Transport{}
+	defer tr.CloseIdleConnections()
+	hc := &http.Client{Transport: tr}
+
 	req, err := http.NewRequest(http.MethodGet, "http://127.0.0.1:9999/debug/pprof/heap", nil)
 	require.NoError(t, err)
 
@@ -70,9 +131,17 @@ func TestPprof(t *testing.T) {
 	require.NoError(t, err)
 	defer res.Body.Close()
 
-	require.Equal(t, http.StatusOK, res.StatusCode)
+	require.Equal(t, http.StatusUnauthorized, res.StatusCode)
+	require.Equal(t, `Basic realm="mediamtx"`, res.Header.Get("WWW-Authenticate"))
 
-	byts, err := io.ReadAll(res.Body)
+	req, err = http.NewRequest(http.MethodGet, "http://myuser:mypass@127.0.0.1:9999/debug/pprof/heap", nil)
 	require.NoError(t, err)
-	require.NotEmpty(t, byts)
+
+	res, err = hc.Do(req)
+	require.NoError(t, err)
+	defer res.Body.Close()
+
+	require.Equal(t, http.StatusUnauthorized, res.StatusCode)
+
+	require.Equal(t, 2, n)
 }

internal/test/auth_manager.go

@@ -24,6 +24,4 @@ var NilAuthManager = &AuthManager{
 	AuthenticateImpl: func(_ *auth.Request) *auth.Error {
 		return nil
 	},
-	RefreshJWTJWKSImpl: func() {
-	},
 }