Fix: Remove redundant error logging for Lua filter execution

server/errors/errors.go

@@ -214,7 +214,6 @@ var (
 	ErrNoFiltersDefined         = errors.New("no filters defined")
 	ErrFilterLuaNameMissing     = errors.New("filter 'name' sttribute missing")
 	ErrFilterLuaScriptPathEmpty = errors.New("filter 'script_path' attribute missing")
-	ErrFilterFailed             = errors.New("filter failed")
 )
 
 // misc.

server/lua-plugins.d/filters/monitoring.lua

@@ -142,16 +142,37 @@ function nauthilus_call_filter(request)
     local session = get_dovecot_session()
 
     if session then
+        local result = {}
+
         local valid_servers = preprocess_backend_servers(nauthilus_backend.get_backend_servers())
         local num_of_bs = nauthilus_util.table_length(valid_servers)
 
+        if request.debug then
+            result.caller = N .. ".lua"
+            result.level = "debug"
+            result.ts = nauthilus_util.get_current_timestamp()
+            result.session = request.session
+            result.dovecot_session = session
+            result.protocol = request.protocol
+            result.account = request.account
+            result.backend_servers_alive = tostring(num_of_bs)
+
+            local backend_servers_hosts = {}
+            for _, server in ipairs(valid_servers) do
+                table.insert(backend_servers_hosts, server.host)
+            end
+
+            result.backend_servers = table.concat(backend_servers_hosts, ", ")
+        end
+
         if num_of_bs > 0 then
             local maybe_server = get_server_from_sessions(session)
 
             if maybe_server then
                 for _, server in ipairs(valid_servers) do
                     if server.host == maybe_server then
                         server_host = maybe_server
+                        result.backend_server_selected = server_host
 
                         break
                     end
@@ -161,9 +182,11 @@ function nauthilus_call_filter(request)
                     invalidate_stale_sessions()
 
                     server_host = valid_servers[math.random(1, num_of_bs)].host
+                    result.backend_server_selected = server_host
                 end
             else
                 server_host = valid_servers[math.random(1, num_of_bs)].host
+                result.backend_server_selected = server_host
             end
         end
 
@@ -178,6 +201,7 @@ function nauthilus_call_filter(request)
             -- Another client might have been faster at the same point in time...
             if expected_server and  server_host ~= expected_server then
                 server_host = expected_server
+                result.backend_server_selected = server_host
             end
 
             attributes["Proxy-Host"] = server_host
@@ -188,11 +212,10 @@ function nauthilus_call_filter(request)
             nauthilus_backend.apply_backend_result(backend_result)
         end
 
-        if server_host == nil then
-            nauthilus_builtin.custom_log_add(N .. "_backend_server", "failed")
-            nauthilus_builtin.status_message_set("No backend servers are available")
+        nauthilus_util.print_result({ log_format = request.log_format }, result, nil)
 
-            return nauthilus_builtin.FILTER_ACCEPT, nauthilus_builtin.FILTER_RESULT_FAIL
+        if server_host == nil then
+            error("No backend servers are available")
         end
     end
 

server/lualib/filter/filter.go

@@ -18,7 +18,6 @@ package filter
 import (
 	"context"
 	stderrors "errors"
-	"fmt"
 	"net/http"
 	"sync"
 	"time"
@@ -27,13 +26,11 @@ import (
 	"github.com/croessner/nauthilus/server/config"
 	"github.com/croessner/nauthilus/server/definitions"
 	"github.com/croessner/nauthilus/server/errors"
-	"github.com/croessner/nauthilus/server/log"
 	"github.com/croessner/nauthilus/server/lualib"
 	"github.com/croessner/nauthilus/server/monitoring"
 	"github.com/croessner/nauthilus/server/stats"
 	"github.com/croessner/nauthilus/server/util"
 	"github.com/gin-gonic/gin"
-	"github.com/go-kit/log/level"
 	"github.com/spf13/viper"
 	"github.com/yuin/gopher-lua"
 )
@@ -462,22 +459,16 @@ func executeScriptWithinContext(request *lua.LTable, script *LuaFilter, r *Reque
 
 	packagePathErr := lualib.PackagePath(L)
 	if packagePathErr != nil {
-		logError(r, script, packagePathErr)
-
 		return false, packagePathErr
 	}
 
 	scriptErr := lualib.DoCompiledFile(L, script.CompiledScript)
 	if scriptErr != nil {
-		logError(r, script, scriptErr)
-
 		return false, scriptErr
 	}
 
 	callErr := L.CallByParam(lua.P{Fn: L.GetGlobal(definitions.LuaFnCallFilter), NRet: 2, Protect: true}, request)
 	if callErr != nil {
-		logError(r, script, callErr)
-
 		return false, callErr
 	}
 
@@ -489,27 +480,13 @@ func executeScriptWithinContext(request *lua.LTable, script *LuaFilter, r *Reque
 
 	logResult(r, script, action, result)
 
-	if result != 0 {
-		err = fmt.Errorf("%v: %s", errors.ErrFilterFailed, script.Name)
-	}
-
 	if action {
 		return true, err
 	}
 
 	return false, err
 }
 
-// logError is a function that logs error information when a LuaFilter script fails during a Request session.
-// It logs the Session GUID, the name of the script, and the error message to the default error logger with an Error level.
-func logError(r *Request, script *LuaFilter, err error) {
-	level.Error(log.Logger).Log(
-		definitions.LogKeyGUID, r.Session,
-		"name", script.Name,
-		definitions.LogKeyMsg, err,
-	)
-}
-
 // logResult logs the output of a LuaFilter execution for a given request.
 // The outcome (ok or fail) and whether an action was taken is logged along with the session ID and script name.
 func logResult(r *Request, script *LuaFilter, action bool, ret int) {
@@ -523,9 +500,11 @@ func logResult(r *Request, script *LuaFilter, action bool, ret int) {
 		"result", resultMap[ret],
 	}
 
-	if r.Logs != nil {
-		for index := range *r.Logs {
-			logs = append(logs, (*r.Logs)[index])
+	if ret != 0 {
+		if r.Logs != nil {
+			for index := range *r.Logs {
+				logs = append(logs, (*r.Logs)[index])
+			}
 		}
 	}