Add tracing

This commit is contained in:
iacore
2024-08-28 13:32:02 +00:00
parent 79bd4fdac3
commit dacd337aec
17 changed files with 125 additions and 47 deletions
+17 -13
View File
@@ -1,21 +1,26 @@
package audit
import (
"context"
"fmt"
"log"
"net/http"
"os"
"path"
"time"
config "codeberg.org/vnpower/pixivfe/v2/config"
"codeberg.org/vnpower/pixivfe/v2/handlers/user_context"
"codeberg.org/vnpower/pixivfe/v2/utils"
"github.com/openzipkin/zipkin-go"
)
const DevDir_Response = "/tmp/pixivfe-dev/resp"
var optionSaveResponse bool
func Init(saveResponse bool) error {
func Init(saveResponse bool, tracer *zipkin.Tracer) error {
optionSaveResponse = saveResponse
utils.Tracer = tracer
if optionSaveResponse {
return os.MkdirAll(DevDir_Response, 0o700)
} else {
@@ -46,35 +51,34 @@ type APIPerformance struct {
ResponseFilename string
}
func LogServerRoundTrip(perf ServerPerformance) {
func LogServerRoundTrip(context context.Context, perf ServerPerformance) {
if perf.Error != nil {
log.Printf("Internal Server Error: %s", perf.Error)
}
if !perf.SkipLogging {
// todo: log.Printf("%v +%v %v %v %v %v %v", time, latency, ip, method, path, status, err)
}
span, _ := utils.Tracer.StartSpanFromContext(context, fmt.Sprintf("%v %v %v %v", perf.Method, perf.Path, perf.Status, perf.Error), zipkin.StartTime(perf.StartTime), zipkin.Parent(user_context.GetUserContext(context).Parent))
span.Tag("RemoteAddr", perf.RemoteAddr)
span.FinishedWithDuration(perf.EndTime.Sub(perf.StartTime))
}
func LogAPIRoundTrip(perf APIPerformance) {
func LogAPIRoundTrip(context context.Context, perf APIPerformance) {
if perf.Response != nil {
if perf.Body != "" && optionSaveResponse {
var err error
perf.ResponseFilename, err = writeResponseBodyToFile(perf.Body)
if err != nil {
log.Println("When saving response to file: ", err)
} else {
log.Println(fmt.Sprintf("[API] %v %v saved to %v", perf.Method, perf.Url, perf.ResponseFilename))
}
}
if !(300 > perf.Response.StatusCode && perf.Response.StatusCode >= 200) {
log.Println("(WARN) non-2xx response from pixiv:")
}
}
// structured logging
if config.GlobalServerConfig.InDevelopment {
// todo
} else {
// todo
}
span, _ := utils.Tracer.StartSpanFromContext(context, fmt.Sprintf("%v %v %v", perf.Method, perf.Url, perf.Error), zipkin.StartTime(perf.StartTime), zipkin.Parent(user_context.GetUserContext(context).Parent))
span.Tag("ResponseFilename", perf.ResponseFilename)
span.FinishedWithDuration(perf.EndTime.Sub(perf.StartTime))
}
func writeResponseBodyToFile(body string) (string, error) {
+1 -1
View File
@@ -4,4 +4,4 @@ import "time"
// todo: make this configurable
const ExpiresIn = 5 * time.Minute
const ProxyCheckerTimeout = 10 * time.Second
const ProxyCheckerTimeout = 10 * time.Second
+1 -1
View File
@@ -104,7 +104,7 @@ type ArtworkBrief struct {
type Illust struct {
ID string `json:"id"`
Title string `json:"title"`
Description HTML `json:"description"`
Description HTML `json:"description"`
UserID string `json:"userId"`
UserName string `json:"userName"`
UserAccount string `json:"userAccount"`
+1 -1
View File
@@ -51,7 +51,7 @@ func GetRankingCalendar(r *http.Request, mode string, year, month int) (HTML, er
if err != nil {
return "", err
}
// Find and print all links on the web page
var links []string
for _, node := range cascadia.QueryAll(doc, selector_img) {
+6 -6
View File
@@ -25,7 +25,7 @@ func API_GET(context context.Context, url string, token string) (SimpleHTTPRespo
start_time := time.Now()
res, resp, err := _API_GET(context, url, token)
end_time := time.Now()
audit.LogAPIRoundTrip(audit.APIPerformance{Response: resp, Error: err, Method: "GET", Url: url, Token: token, Body: res.Body, StartTime: start_time, EndTime: end_time})
audit.LogAPIRoundTrip(context, audit.APIPerformance{Response: resp, Error: err, Method: "GET", Url: url, Token: token, Body: res.Body, StartTime: start_time, EndTime: end_time})
if err != nil {
return SimpleHTTPResponse{}, fmt.Errorf("While GET %s: %w", url, err)
}
@@ -98,21 +98,21 @@ func API_GET_UnwrapJson(context context.Context, url string, token string) (stri
}
// send POST
func API_POST(r *http.Request, url, payload, token, csrf string, isJSON bool) error {
func API_POST(context context.Context, url, payload, token, csrf string, isJSON bool) error {
start_time := time.Now()
resp, err := _API_POST(r, url, payload, token, csrf, isJSON)
resp, err := _API_POST(context, url, payload, token, csrf, isJSON)
end_time := time.Now()
audit.LogAPIRoundTrip(audit.APIPerformance{Response: resp, Error: err, Method: "POST", Url: url, Token: token, Body: "", StartTime: start_time, EndTime: end_time})
audit.LogAPIRoundTrip(context, audit.APIPerformance{Response: resp, Error: err, Method: "POST", Url: url, Token: token, Body: "", StartTime: start_time, EndTime: end_time})
if err != nil {
return fmt.Errorf("While POST %s: %w", url, err)
}
return err
}
func _API_POST(r *http.Request, url, payload, token, csrf string, isJSON bool) (*http.Response, error) {
func _API_POST(context context.Context, url, payload, token, csrf string, isJSON bool) (*http.Response, error) {
requestBody := []byte(payload)
req, err := http.NewRequestWithContext(r.Context(), "POST", url, bytes.NewBuffer(requestBody))
req, err := http.NewRequestWithContext(context, "POST", url, bytes.NewBuffer(requestBody))
if err != nil {
return nil, err
}
+1 -1
View File
@@ -47,7 +47,7 @@ type User struct {
Avatar string `json:"imageBig"`
Following int `json:"following"`
MyPixiv int `json:"mypixivCount"`
Comment HTML `json:"commentHtml"`
Comment HTML `json:"commentHtml"`
Webpage string `json:"webpage"`
SocialRaw json.RawMessage `json:"social"`
Artworks []ArtworkBrief `json:"artworks"`
-6
View File
@@ -1,6 +0,0 @@
# About tracing and telemetry
Every request to pixiv websites should go through core/requests.go.
Every request to pixiv websites is traced.
Every server request is traced.
+23
View File
@@ -0,0 +1,23 @@
# About tracing in PixivFE
Every request to pixiv websites should go through core/requests.go.
Every request to pixiv websites is traced.
Every server request should be traced, but currently not.
## Todo
- [x] Trace asset route
- [x] Trace every server route
## How to use tracing
```
wget https://repo1.maven.org/maven2/io/zipkin/zipkin-server/3.4.1/zipkin-server-3.4.1-exec.jar
java -jar zipkin-server-3.4.1-exec.jar
# start pixivfe
```
That's it!
To see the spans, open http://localhost:9411/ and click "RUN QUERY".
+1
View File
@@ -9,6 +9,7 @@ require (
github.com/go-faker/faker/v4 v4.5.0
github.com/goccy/go-json v0.10.3
github.com/gorilla/mux v1.8.1
github.com/openzipkin/zipkin-go v0.4.3
github.com/playwright-community/playwright-go v0.4501.1
github.com/tidwall/gjson v1.17.3
golang.org/x/net v0.28.0
+6
View File
@@ -26,6 +26,8 @@ github.com/gorilla/mux v1.8.1 h1:TuBL49tXwgrFYWhqrNgrUNEY92u81SPhu7sTdzQEiWY=
github.com/gorilla/mux v1.8.1/go.mod h1:AKf9I4AEqPTmMytcMc0KkNouC66V3BtZ4qD5fmWSiMQ=
github.com/mitchellh/go-ps v1.0.0 h1:i6ampVEEF4wQFF+bkYfwYgY+F/uYJDktmvLPf7qIgjc=
github.com/mitchellh/go-ps v1.0.0/go.mod h1:J4lOc8z8yJs6vUwklHw2XEIiT4z4C40KtWVN3nvg8Pg=
github.com/openzipkin/zipkin-go v0.4.3 h1:9EGwpqkgnwdEIJ+Od7QVSEIH+ocmm5nPat0G7sjsSdg=
github.com/openzipkin/zipkin-go v0.4.3/go.mod h1:M9wCJZFWCo2RiY+o1eBCEMe0Dp2S5LDHcMZmk3RmK7c=
github.com/playwright-community/playwright-go v0.4501.1 h1:kz8SIfR6nEI8blk77nTVD0K5/i37QP5rY/o8a1fG+4c=
github.com/playwright-community/playwright-go v0.4501.1/go.mod h1:bpArn5TqNzmP0jroCgw4poSOG9gSeQg490iLqWAaa7w=
github.com/pmezard/go-difflib v1.0.0 h1:4DBwDE0NGyQoBHbLQYPwSUPoCMWR5BEzIk/f1lZbAQM=
@@ -71,6 +73,8 @@ golang.org/x/sys v0.5.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.7.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.8.0/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg=
golang.org/x/sys v0.17.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=
golang.org/x/sys v0.24.0 h1:Twjiwq9dn6R1fQcyiK+wQyHWfaz/BJB+YIpzU/Cv3Xg=
golang.org/x/sys v0.24.0/go.mod h1:/VUhepiaJMQUp4+oa/7Zr1D23ma6VTLIYjOOTFZPUcA=
golang.org/x/term v0.0.0-20201126162022-7de9c90e9dd1/go.mod h1:bj7SfCRtBDWHUb9snDiAeCFNEtKQo2Wmx5Cou7ajbmo=
golang.org/x/term v0.0.0-20210927222741-03fcf44c2211/go.mod h1:jbD1KX2456YbFQfuXm/mYQcufACuNUgVhRMnK/tPxf8=
golang.org/x/term v0.5.0/go.mod h1:jMB1sMXY+tzblOD4FWmEbocvup2/aLOaQEp7JmGp78k=
@@ -92,6 +96,8 @@ golang.org/x/tools v0.0.0-20191119224855-298f0cb1881e/go.mod h1:b+2E5dAYhXwXZwtn
golang.org/x/tools v0.1.12/go.mod h1:hNGJHUnrk76NpqgfD5Aqm5Crs+Hm0VOH/i9J2+nxYbc=
golang.org/x/tools v0.6.0/go.mod h1:Xwgl3UAJ/d3gWutnCtw505GrjyAbvKui8lOU390QaIU=
golang.org/x/xerrors v0.0.0-20190717185122-a985d3407aa7/go.mod h1:I/5z698sn9Ka8TeJc9MKroUUfqBBauWjQqLJ2OPfmY0=
google.golang.org/grpc v1.63.2 h1:MUeiw1B2maTVZthpU5xvASfTh3LDbxHd6IJ6QQVU+xM=
google.golang.org/grpc v1.63.2/go.mod h1:WAX/8DgncnokcFUldAxq7GeB5DXHDbMF+lLvDomNkRA=
gopkg.in/check.v1 v0.0.0-20161208181325-20d25e280405/go.mod h1:Co6ibVJAznAaIkqp8huTwlJQCZ016jof/cbN4VW5Yz0=
gopkg.in/yaml.v3 v3.0.0-20200313102051-9f266ea9e77c/go.mod h1:K4uyk7z7BCEPqu6E+C64Yfv1cQ7kz7rIZviUmN+EgEM=
gopkg.in/yaml.v3 v3.0.1 h1:fxVm/GzAzEWqLHuvctI91KS9hhNmmWOoWu0XTYJS7CA=
+3 -9
View File
@@ -8,20 +8,14 @@ import (
"net/http/httptest"
"slices"
"codeberg.org/vnpower/pixivfe/v2/handlers/user_context"
"codeberg.org/vnpower/pixivfe/v2/routes"
)
type UserContext struct {
Err error
ErrorStatusCodeOverride int
}
type userContextKey struct{}
var UserContextKey = userContextKey{}
type UserContext = user_context.UserContext
func GetUserContext(r *http.Request) *UserContext {
return r.Context().Value(UserContextKey).(*UserContext)
return user_context.GetUserContext(r.Context())
}
func CatchError(handler func(w http.ResponseWriter, r *http.Request) error) http.HandlerFunc {
+4 -4
View File
@@ -1,12 +1,12 @@
package handlers
import (
"context"
"net/http"
"strings"
"time"
"codeberg.org/vnpower/pixivfe/v2/audit"
"codeberg.org/vnpower/pixivfe/v2/handlers/user_context"
)
type ResponseWriterInterceptStatus struct {
@@ -36,7 +36,7 @@ func LogRequest(f func(w http.ResponseWriter, r *http.Request)) func(w http.Resp
ResponseWriter: w_,
}
// set user context
r = r.WithContext(context.WithValue(r.Context(), UserContextKey, &UserContext{}))
r = r.WithContext(user_context.WithContext(r.Context()))
start_time := time.Now()
@@ -44,14 +44,14 @@ func LogRequest(f func(w http.ResponseWriter, r *http.Request)) func(w http.Resp
end_time := time.Now()
audit.LogServerRoundTrip(audit.ServerPerformance{
audit.LogServerRoundTrip(r.Context(), audit.ServerPerformance{
StartTime: start_time,
EndTime: end_time,
RemoteAddr: r.RemoteAddr,
Method: r.Method,
Path: r.URL.Path,
Status: w.statusCode,
Error: GetUserContext(r).Err,
Error: GetUserContext(r).Err,
SkipLogging: CanRequestSkipLogger(r),
})
}
+1 -1
View File
@@ -25,7 +25,7 @@ func DefineRoutes() *mux.Router {
return r.URL.Path != "/" && strings.HasSuffix(r.URL.Path, "/")
}).HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
url := r.URL
url.Path = url.Path[0:len(url.Path)-1]
url.Path = url.Path[0 : len(url.Path)-1]
http.Redirect(w, r, url.String(), http.StatusPermanentRedirect)
})
+31
View File
@@ -0,0 +1,31 @@
// pain: why go no cyclic import
package user_context
import (
"context"
"codeberg.org/vnpower/pixivfe/v2/utils"
"github.com/openzipkin/zipkin-go/model"
)
type UserContext struct {
Parent model.SpanContext
Err error
ErrorStatusCodeOverride int
}
type UserContextKeyType struct{}
var UserContextKey = UserContextKeyType{}
func GetUserContext(context context.Context) *UserContext {
return context.Value(UserContextKey).(*UserContext)
}
func WithContext(ctx context.Context) context.Context {
traceId, ctx := utils.Tracer.StartSpanFromContext(ctx, "")
return context.WithValue(ctx, UserContextKey, &UserContext{
Parent: traceId.Context(),
})
}
+21 -1
View File
@@ -11,6 +11,9 @@ import (
"runtime"
"syscall"
"github.com/openzipkin/zipkin-go"
zipkin_httpreporter "github.com/openzipkin/zipkin-go/reporter/http"
"codeberg.org/vnpower/pixivfe/v2/audit"
"codeberg.org/vnpower/pixivfe/v2/config"
"codeberg.org/vnpower/pixivfe/v2/handlers"
@@ -18,8 +21,25 @@ import (
)
func main() {
reporter := zipkin_httpreporter.NewReporter("http://localhost:9411/api/v2/spans")
defer func() {
_ = reporter.Close()
}()
// this is purely theoretical. the port is used for distributed tracing.
endpoint, err := zipkin.NewEndpoint("pixivfe", "localhost:8282")
if err != nil {
log.Fatalf("unable to create local endpoint: %+v\n", err)
}
// initialize our tracer
tracer, err := zipkin.NewTracer(reporter, zipkin.WithLocalEndpoint(endpoint))
if err != nil {
log.Fatalf("unable to create tracer: %+v\n", err)
}
config.GlobalServerConfig.LoadConfig()
audit.Init(config.GlobalServerConfig.InDevelopment)
audit.Init(config.GlobalServerConfig.InDevelopment, tracer)
template.Init(config.GlobalServerConfig.InDevelopment)
// Initialize and start the proxy checker
+3 -3
View File
@@ -30,7 +30,7 @@ func AddBookmarkRoute(w http.ResponseWriter, r *http.Request) error {
"comment": "",
"tags": []
}`, id)
if err := core.API_POST(r, URL, payload, token, csrf, true); err != nil {
if err := core.API_POST(r.Context(), URL, payload, token, csrf, true); err != nil {
return err
}
@@ -54,7 +54,7 @@ func DeleteBookmarkRoute(w http.ResponseWriter, r *http.Request) error {
// You can't unlike
URL := "https://www.pixiv.net/ajax/illusts/bookmarks/delete"
payload := fmt.Sprintf(`bookmark_id=%s`, id)
if err := core.API_POST(r, URL, payload, token, csrf, false); err != nil {
if err := core.API_POST(r.Context(), URL, payload, token, csrf, false); err != nil {
return err
}
@@ -77,7 +77,7 @@ func LikeRoute(w http.ResponseWriter, r *http.Request) error {
URL := "https://www.pixiv.net/ajax/illusts/like"
payload := fmt.Sprintf(`{"illust_id": "%s"}`, id)
if err := core.API_POST(r, URL, payload, token, csrf, true); err != nil {
if err := core.API_POST(r.Context(), URL, payload, token, csrf, true); err != nil {
return err
}
+5
View File
@@ -0,0 +1,5 @@
package utils
import "github.com/openzipkin/zipkin-go"
var Tracer *zipkin.Tracer