logging.Server prints a wrong caller path

[kvii]

What happened:

Consider this code:

logger := log.With(log.NewStdLogger(os.Stdout),
	"caller", log.DefaultCaller,
)

helper := log.NewHelper(logger)
helper.Info("foo")

srv := http.NewServer(
	http.Address(":9090"),
	http.Middleware(logging.Server(logger)),
)

helper.Info's caller field report where the helper.Info called (e.g. main.go:10). But logger in logger.Server is not.

What you expected to happen:

logger.Server's caller path "level" should same as "helper.Log"

How to reproduce it (as minimally and precisely as possible):

Please refer this repo.

Anything else we need to know?:

这绝对不是调一下 caller 层数或添加自定义 calller 逻辑（比如 for 循环匹配第一个不是 kratos 的目录）能解决的问题。

Environment:

• Kratos version (use kratos -v): v2.7.2
• Go version (use go version): 1.21.5
• OS (e.g: cat /etc/os-release): -
• Others: -

[dosubot]

🤖

你好 @kvii，我是 Dosu，一个可以帮助你解决bug，回答问题，甚至成为贡献者的机器人。在等待人类维护者回复的同时，我在这里为你提供帮助。

The issue you're experiencing might be due to the way the logger is set up in your test. The DefaultCaller function in Kratos logs the file and line number of the caller's caller. This means that when you call logger.Log, the caller is TestInfo, but the caller's caller is the testing framework itself, not your TestInfo function. This is why the caller path is not at the same level as helper.Log.

To reproduce this issue, you can create a helper function that calls logger.Log and call this helper function from TestInfo. Here's an example:

package log

import (
	"testing"
)

func TestInfo(_ *testing.T) {
	logger := DefaultLogger
	logger = With(logger, "ts", DefaultTimestamp)
	logger = With(logger, "caller", DefaultCaller)
	logHelper(logger)
}

func logHelper(logger Logger) {
	_ = logger.Log(LevelInfo, "key1", "value1")
}

In this example, DefaultCaller will log the file and line number of logHelper, not TestInfo. This is because logHelper is the caller of logger.Log, but TestInfo is the caller's caller.

I found two similar issues in the Kratos repository that have been solved:

1. [BUG] keep kratos internal log caller depth same which was last updated on November 10, 2023
2. [Bug] The caller depth of log.Filter should be the same as log.logger. which was last updated on August 16, 2023

These issues might provide some insight into your problem.

As for the exact functionality of the logging.Server function in the Kratos framework, I wasn't able to find a specific answer within the repository. It might be beneficial to look into the Kratos documentation or source code for more information.

I hope this helps! If you have any more questions or need further clarification, feel free to ask.

Best,
Dosu

Sources

• [BUG] keep kratos internal log caller depth same
• [Bug] The caller depth of log.Filter should be the same as log.logger.
• log/log_test.go

---

This response is meant to be useful and save you time. It is not meant to be a precise solution, but rather a starting point for your own research.

Help me be more useful! Please leave a 👍 if this is helpful and 👎 if it is irrelevant.

If you want to continue the conversation, start your reply with @dosu-bot.