英文:
Get stacktrace when context.Context is canceled by http.TimeoutHandler
问题
为了调试目的，我如何获取有关我的http.TimeoutHandler包装处理程序取消活动http.Request::Context()的确切位置的更多信息？
理想情况下，应该记录堆栈跟踪。
背景：服务器的设置如下：
mux := http.NewServeMux()
mux.Handle("/", http.HandlerFunc(handle_root))
srv := &http.Server {
Addr : fmt.Sprintf("%s:%d", args.address, args.port),
ReadTimeout : 2 * time.Second,
WriteTimeout : 2 * time.Second,
IdleTimeout : 2 * time.Second,
Handler : http.TimeoutHandler(mux, 1500 * time.Millisecond,
"Backend timeout exceeded"),
}
log.Fatal(srv.ListenAndServe())
其中handle_root()调用一些辅助函数，并将http.Request的Context()传递给一些database.sql准备好的语句QueryContext()调用。
当超时超过时，为了调试/分析，获取一些关于执行进度的提示将非常有帮助，例如是否正在等待某个特定SQL语句的结果集，以及如果是的话，是哪个语句。
因此，在取消点处提供堆栈跟踪将提供此信息。
默认情况下，不记录任何内容，而我的测试客户端收到了预期的'503 Service Unavailable/Backend timeout exceeded'回复。
英文:
For debugging purposes, how can I get more information on exactly where my http.TimeoutHandler wrapped handler canceled an active http.Request::Context()?
Ideally, a stacktrace should be logged.
Background: The server is set up like this:
mux := http.NewServeMux()
mux.Handle("/", http.HandlerFunc(handle_root))
srv := &http.Server {
Addr : fmt.Sprintf("%s:%d", args.address, args.port),
ReadTimeout : 2 * time.Second,
WriteTimeout : 2 * time.Second,
IdleTimeout : 2 * time.Second,
Handler : http.TimeoutHandler(mux, 1500 * time.Millisecond,
"Backend timeout exceeded"),
}
log.Fatal(srv.ListenAndServe())
Where handle_root() calls some helper functions and passes the http.Requests Context() to some database.sql prepared statements QueryContext() calls.
When the timeout is exceeded it would be helpful for debugging/profiling to get some hint on exactly how far the execution proceeded into the handler, e.g. whether it was waiting on the result set of a certain SQL statement or not - and if it was on which one exactly.
Hence, a stacktrace at the point of cancellation should provide this information.
By default, nothing is logged, while my test client receives the expected '503 Service Unavailable/Backend timeout exceeded' reply.
答案1
得分: 0
由于上下文参数化函数中的上下文取消通常会导致它们返回一个非nil的错误，所以在错误返回时转储堆栈也会捕获超时。
可以通过错误消息文本来识别这些错误，例如：
context deadline exceeded
pq: canceling statement due to user request
http: Handler timeout
由于在Go中错误是通过错误代码报告的（而不是异常），并且在每个返回错误的函数调用后已经必须添加错误检查样板代码，因此可以在那里集成堆栈转储，例如：
import (
// ...
"runtime/debug"
// ...
)
func internal_error(w http.ResponseWriter, err error) int {
log.Printf("ERROR: %s [[[%s]]]", err, debug.Stack())
status := 500
w.WriteHeader(status)
w.Write([]byte(`<html>
<head><title>Internal Server Error</title></head>
<body><h1>Internal Server Error (500)</h1></body></html>`))
return status
}
func handle_something(w http.ResponseWriter, r *http.Request) {
// ...
payload, err := select_from_some_table(r.Context(), arg0)
if err != nil {
internal_error(w, err)
return
}
// ...
}
此外，取消SQL语句时，默认情况下数据库可能会记录这些取消的语句。例如，Postgresql是这样做的：
cat /var/lib/pgsql/data/log/postgresql-2023-02-26.log
[..]
2023-02-26 16:51:29.024 UTC [338398] ERROR: canceling statement due to user request
2023-02-26 16:51:29.024 UTC [338398] STATEMENT:
SELECT tt.section, tt.name FROM (
SELECT DISTINCT section, name FROM ([..]
[..]
英文:
Since context cancellations in context parametrized functions usually result in them returning a non-nil error, dumping the stack on error return also catches timeouts.
They can then be identified by error message text such as:
context deadline exceeded
pq: canceling statement due to user request
http: Handler timeout
As errors are reported via error codes in Go (and not exceptions) and one already has to add error checking boilerplate after each Error returning function call, one can integrate stackdumping there, e.g.:
import (
// ...
"runtime/debug"
// ...
)
func internal_error(w http.ResponseWriter, err error) int {
log.Printf("ERROR: %s [[[%s]]]", err, debug.Stack())
status := 500
w.WriteHeader(status)
w.Write([]byte(`<html>
<head><title>Internal Server Error</title></head>
<body><h1>Internal Server Error (500)</h1></body></html>`))
return status
}
func handle_something(w http.ResponseWriter, r *http.Request) {
// ...
payload, err := select_from_some_table(r.Context(), arg0)
if err != nil {
internal_error(w, err)
return
}
// ...
}
In addition, when cancelling SQL statements the database might log such cancelled statements, by default. For example, Postgresql does it like this:
cat /var/lib/pgsql/data/log/postgresql-2023-02-26.log
[..]
2023-02-26 16:51:29.024 UTC [338398] ERROR: canceling statement due to user request
2023-02-26 16:51:29.024 UTC [338398] STATEMENT:
SELECT tt.section, tt.name FROM (
SELECT DISTINCT section, name FROM ([..]
[..]
通过集体智慧和协作来改善编程学习和解决问题的方式。致力于成为全球开发者共同参与的知识库，让每个人都能够通过互相帮助和分享经验来进步。
评论