diff --git a/audit/logging.go b/audit/tracing.go similarity index 56% rename from audit/logging.go rename to audit/tracing.go index b749eb8..455b9a5 100644 --- a/audit/logging.go +++ b/audit/tracing.go @@ -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) { diff --git a/config/constant.go b/config/constant.go index ba87701..2a3b70c 100644 --- a/config/constant.go +++ b/config/constant.go @@ -4,4 +4,4 @@ import "time" // todo: make this configurable const ExpiresIn = 5 * time.Minute -const ProxyCheckerTimeout = 10 * time.Second \ No newline at end of file +const ProxyCheckerTimeout = 10 * time.Second diff --git a/core/artwork.go b/core/artwork.go index 518b426..135826d 100644 --- a/core/artwork.go +++ b/core/artwork.go @@ -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"` diff --git a/core/rankingCalendar.go b/core/rankingCalendar.go index f8d8c75..ac9220b 100644 --- a/core/rankingCalendar.go +++ b/core/rankingCalendar.go @@ -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) { diff --git a/core/requests.go b/core/requests.go index b74766b..909512e 100644 --- a/core/requests.go +++ b/core/requests.go @@ -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 } diff --git a/core/user.go b/core/user.go index bb34ec9..3f0865e 100644 --- a/core/user.go +++ b/core/user.go @@ -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"` diff --git a/doc/dev/features/auditing.md b/doc/dev/features/auditing.md deleted file mode 100644 index 12d1ea2..0000000 --- a/doc/dev/features/auditing.md +++ /dev/null @@ -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. diff --git a/doc/dev/features/tracing.md b/doc/dev/features/tracing.md new file mode 100644 index 0000000..9526248 --- /dev/null +++ b/doc/dev/features/tracing.md @@ -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". diff --git a/go.mod b/go.mod index 655eb44..6de4f6b 100644 --- a/go.mod +++ b/go.mod @@ -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 diff --git a/go.sum b/go.sum index b66d687..45b6afb 100644 --- a/go.sum +++ b/go.sum @@ -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= diff --git a/handlers/error_handler.go b/handlers/error_handler.go index 8e41f8e..ba21cbb 100644 --- a/handlers/error_handler.go +++ b/handlers/error_handler.go @@ -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 { diff --git a/handlers/logger.go b/handlers/logger.go index e7eaf6f..29dd6cd 100644 --- a/handlers/logger.go +++ b/handlers/logger.go @@ -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), }) } diff --git a/handlers/router.go b/handlers/router.go index 7cbacc7..8860dae 100644 --- a/handlers/router.go +++ b/handlers/router.go @@ -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) }) diff --git a/handlers/user_context/user_context.go b/handlers/user_context/user_context.go new file mode 100644 index 0000000..a2c4084 --- /dev/null +++ b/handlers/user_context/user_context.go @@ -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(), + }) +} diff --git a/main.go b/main.go index 8abef75..7511308 100644 --- a/main.go +++ b/main.go @@ -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 diff --git a/routes/actions.go b/routes/actions.go index d19e06e..96a37ab 100644 --- a/routes/actions.go +++ b/routes/actions.go @@ -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 } diff --git a/utils/global_tracer.go b/utils/global_tracer.go new file mode 100644 index 0000000..2eec91b --- /dev/null +++ b/utils/global_tracer.go @@ -0,0 +1,5 @@ +package utils + +import "github.com/openzipkin/zipkin-go" + +var Tracer *zipkin.Tracer