Web Server and CI Improvements (#374)

* Fix for infinite redirect loop

path.Join trims the trailing slash if the path isn't /, use configured
root instead.

* Add repo root independence

This makes the workflows agnostic of the repository root, making it
possible to build in forked repos.

* Add HTTP request logging

* Fix proper RootPath handler

* Add logging for all resources

This adds proper logging for all resources, including errors. Logging
is on by default, but can be turned off.

* Report effective length of written data

.github/workflows/_buildx.yml

@@ -25,8 +25,8 @@ jobs:
       - name: Buildx
         working-directory: .github/workflows/docker
         run: |
-          echo ${{ secrets.GITHUB_TOKEN }} | docker login -u go-shiori --password-stdin ghcr.io
-          REPO=ghcr.io/go-shiori/shiori
+          echo "${{ secrets.GITHUB_TOKEN }}" | docker login -u "${{ github.repository_owner }}" --password-stdin ghcr.io
+          REPO=ghcr.io/${{ github.repository }}
           TAG=$(git describe --tags)
           if [ -z "$(git tag --points-at HEAD)" ]
           then

.github/workflows/version_bump.yml

@@ -21,8 +21,8 @@ jobs:
           ref: master
       - name: Tag release
         run: |
-          git config user.email "go-shiori@users.noreply.github.com"
-          git config user.name "shiori"
+          git config user.email "${{github.repository_owner}}@users.noreply.github.com"
+          git config user.name "${{github.repository_owner}}"
           git tag -a ${{ github.event.inputs.version }} -m "tag release ${{ github.event.inputs.version }}"
           git push --follow-tags
   call-gorelease:

internal/cmd/serve.go

@@ -21,6 +21,7 @@ func serveCmd() *cobra.Command {
 	cmd.Flags().IntP("port", "p", 8080, "Port used by the server")
 	cmd.Flags().StringP("address", "a", "", "Address the server listens to")
 	cmd.Flags().StringP("webroot", "r", "/", "Root path that used by server")
+	cmd.Flags().Bool("log", true, "Print out a non-standard access log")
 
 	return cmd
 }
@@ -30,6 +31,7 @@ func serveHandler(cmd *cobra.Command, args []string) {
 	port, _ := cmd.Flags().GetInt("port")
 	address, _ := cmd.Flags().GetString("address")
 	rootPath, _ := cmd.Flags().GetString("webroot")
+	log, _ := cmd.Flags().GetBool("log")
 
 	// Validate root path
 	if rootPath == "" {
@@ -51,6 +53,7 @@ func serveHandler(cmd *cobra.Command, args []string) {
 		ServerAddress: address,
 		ServerPort:    port,
 		RootPath:      rootPath,
+		Log:           log,
 	}
 
 	err := webserver.ServeApp(serverConfig)

internal/webserver/handler.go

@@ -21,6 +21,7 @@ type handler struct {
 	UserCache    *cch.Cache
 	SessionCache *cch.Cache
 	ArchiveCache *cch.Cache
+	Log          bool
 
 	templates map[string]*template.Template
 }

internal/webserver/server.go

@@ -19,9 +19,92 @@ type Config struct {
 	ServerAddress string
 	ServerPort    int
 	RootPath      string
+	Log           bool
 }
 
-// ServeApp serves wb interface in specified port
+// ErrorResponse defines a single HTTP error response.
+type ErrorResponse struct {
+	Code        int
+	Body        string
+	contentType string
+	errorText   string
+	Log         bool
+}
+
+func (e *ErrorResponse) Error() string {
+	return e.errorText
+}
+
+func (e *ErrorResponse) ServeHTTP(w http.ResponseWriter, r *http.Request) {
+	if e.contentType != "" {
+		w.Header().Set("Content-Type", e.contentType)
+	}
+	body := e.Body
+	if e.Code != 0 {
+		w.WriteHeader(e.Code)
+	}
+	written := 0
+	if len(body) > 0 {
+		written, _ = w.Write([]byte(body))
+	}
+	if e.Log {
+		Logger(r, e.Code, written)
+	}
+}
+
+// responseData will hold response details that we are interested in for logging
+type responseData struct {
+	status int
+	size   int
+}
+
+// Wrapper around http.ResponseWriter to be able to catch calls to Write*()
+type loggingResponseWriter struct {
+	http.ResponseWriter
+	responseData *responseData
+}
+
+// Collect response size for each Write(). Also behave as the internal
+// http.ResponseWriter by implicitely setting the status code to 200 at the
+// first write.
+func (r *loggingResponseWriter) Write(b []byte) (int, error) {
+	size, err := r.ResponseWriter.Write(b) // write response using original http.ResponseWriter
+	r.responseData.size += size            // capture size
+	// Documented implicit WriteHeader(http.StatusOK) with first call to Write
+	if r.responseData.status == 0 {
+		r.responseData.status = http.StatusOK
+	}
+	return size, err
+}
+
+// Capture calls to WriteHeader, might be called on errors.
+func (r *loggingResponseWriter) WriteHeader(statusCode int) {
+	r.ResponseWriter.WriteHeader(statusCode) // write status code using original http.ResponseWriter
+	r.responseData.status = statusCode       // capture status code
+}
+
+// Log through logrus, 200 will log as info, anything else as an error.
+func Logger(r *http.Request, statusCode int, size int) {
+	if statusCode == http.StatusOK {
+		logrus.WithFields(logrus.Fields{
+			"proto":  r.Proto,
+			"remote": r.RemoteAddr,
+			"reqlen": r.ContentLength,
+			"size":   size,
+			"status": statusCode,
+		}).Info(r.Method, " ", r.RequestURI)
+	} else {
+		logrus.WithFields(logrus.Fields{
+			"proto":  r.Proto,
+			"remote": r.RemoteAddr,
+			"reqlen": r.ContentLength,
+			"size":   size,
+			"status": statusCode,
+		}).Warn(r.Method, " ", r.RequestURI)
+	}
+}
+
+// ServeApp serves web interface in specified port
 func ServeApp(cfg Config) error {
 	// Create handler
 	hdl := handler{
@@ -31,6 +114,7 @@ func ServeApp(cfg Config) error {
 		SessionCache: cch.New(time.Hour, 10*time.Minute),
 		ArchiveCache: cch.New(time.Minute, 5*time.Minute),
 		RootPath:     cfg.RootPath,
+		Log:          cfg.Log,
 	}
 
 	hdl.prepareSessionCache()
@@ -41,46 +125,98 @@ func ServeApp(cfg Config) error {
 		return fmt.Errorf("failed to prepare templates: %v", err)
 	}
 
-	// Create router
+	// Prepare errors
+	var (
+		ErrorNotAllowed = &ErrorResponse{
+			http.StatusMethodNotAllowed,
+			"Method is not allowed",
+			"text/plain; charset=UTF-8",
+			"MethodNotAllowedError",
+			cfg.Log,
+		}
+		ErrorNotFound = &ErrorResponse{
+			http.StatusNotFound,
+			"Resource Not Found",
+			"text/plain; charset=UTF-8",
+			"NotFoundError",
+			cfg.Log,
+		}
+	)
+
+	// Create router and register error handlers
 	router := httprouter.New()
+	router.NotFound = ErrorNotFound
+	router.MethodNotAllowed = ErrorNotAllowed
+
+	// withLogging will inject our own (compatible) http.ResponseWriter in order
+	// to collect details about the answer, i.e. the status code and the size of
+	// data in the response. Once done, these are passed further for logging, if
+	// relevant.
+	withLogging := func(req func(http.ResponseWriter, *http.Request, httprouter.Params)) func(http.ResponseWriter, *http.Request, httprouter.Params) {
+		return func(w http.ResponseWriter, r *http.Request, ps httprouter.Params) {
+			d := &responseData{
+				status: 0,
+				size:   0,
+			}
+			lrw := loggingResponseWriter{
+				ResponseWriter: w,
+				responseData:   d,
+			}
+			req(&lrw, r, ps)
+			if hdl.Log {
+				Logger(r, d.status, d.size)
+			}
+		}
+	}
 
 	// jp here means "join path", as in "join route with root path"
 	jp := func(route string) string {
 		return path.Join(cfg.RootPath, route)
 	}
 
-	router.GET(jp("/js/*filepath"), hdl.serveJsFile)
-	router.GET(jp("/res/*filepath"), hdl.serveFile)
-	router.GET(jp("/css/*filepath"), hdl.serveFile)
-	router.GET(jp("/fonts/*filepath"), hdl.serveFile)
+	router.GET(jp("/js/*filepath"), withLogging(hdl.serveJsFile))
+	router.GET(jp("/res/*filepath"), withLogging(hdl.serveFile))
+	router.GET(jp("/css/*filepath"), withLogging(hdl.serveFile))
+	router.GET(jp("/fonts/*filepath"), withLogging(hdl.serveFile))
 
-	router.GET(jp("/"), hdl.serveIndexPage)
-	router.GET(jp("/login"), hdl.serveLoginPage)
-	router.GET(jp("/bookmark/:id/thumb"), hdl.serveThumbnailImage)
-	router.GET(jp("/bookmark/:id/content"), hdl.serveBookmarkContent)
-	router.GET(jp("/bookmark/:id/archive/*filepath"), hdl.serveBookmarkArchive)
+	router.GET(cfg.RootPath, withLogging(hdl.serveIndexPage))
+	router.GET(jp("/login"), withLogging(hdl.serveLoginPage))
+	router.GET(jp("/bookmark/:id/thumb"), withLogging(hdl.serveThumbnailImage))
+	router.GET(jp("/bookmark/:id/content"), withLogging(hdl.serveBookmarkContent))
+	router.GET(jp("/bookmark/:id/archive/*filepath"), withLogging(hdl.serveBookmarkArchive))
 
-	router.POST(jp("/api/login"), hdl.apiLogin)
-	router.POST(jp("/api/logout"), hdl.apiLogout)
-	router.GET(jp("/api/bookmarks"), hdl.apiGetBookmarks)
-	router.GET(jp("/api/tags"), hdl.apiGetTags)
-	router.PUT(jp("/api/tag"), hdl.apiRenameTag)
-	router.POST(jp("/api/bookmarks"), hdl.apiInsertBookmark)
-	router.DELETE(jp("/api/bookmarks"), hdl.apiDeleteBookmark)
-	router.PUT(jp("/api/bookmarks"), hdl.apiUpdateBookmark)
-	router.PUT(jp("/api/cache"), hdl.apiUpdateCache)
-	router.PUT(jp("/api/bookmarks/tags"), hdl.apiUpdateBookmarkTags)
-	router.POST(jp("/api/bookmarks/ext"), hdl.apiInsertViaExtension)
-	router.DELETE(jp("/api/bookmarks/ext"), hdl.apiDeleteViaExtension)
+	router.POST(jp("/api/login"), withLogging(hdl.apiLogin))
+	router.POST(jp("/api/logout"), withLogging(hdl.apiLogout))
+	router.GET(jp("/api/bookmarks"), withLogging(hdl.apiGetBookmarks))
+	router.GET(jp("/api/tags"), withLogging(hdl.apiGetTags))
+	router.PUT(jp("/api/tag"), withLogging(hdl.apiRenameTag))
+	router.POST(jp("/api/bookmarks"), withLogging(hdl.apiInsertBookmark))
+	router.DELETE(jp("/api/bookmarks"), withLogging(hdl.apiDeleteBookmark))
+	router.PUT(jp("/api/bookmarks"), withLogging(hdl.apiUpdateBookmark))
+	router.PUT(jp("/api/cache"), withLogging(hdl.apiUpdateCache))
+	router.PUT(jp("/api/bookmarks/tags"), withLogging(hdl.apiUpdateBookmarkTags))
+	router.POST(jp("/api/bookmarks/ext"), withLogging(hdl.apiInsertViaExtension))
+	router.DELETE(jp("/api/bookmarks/ext"), withLogging(hdl.apiDeleteViaExtension))
 
-	router.GET(jp("/api/accounts"), hdl.apiGetAccounts)
-	router.PUT(jp("/api/accounts"), hdl.apiUpdateAccount)
-	router.POST(jp("/api/accounts"), hdl.apiInsertAccount)
-	router.DELETE(jp("/api/accounts"), hdl.apiDeleteAccount)
+	router.GET(jp("/api/accounts"), withLogging(hdl.apiGetAccounts))
+	router.PUT(jp("/api/accounts"), withLogging(hdl.apiUpdateAccount))
+	router.POST(jp("/api/accounts"), withLogging(hdl.apiInsertAccount))
+	router.DELETE(jp("/api/accounts"), withLogging(hdl.apiDeleteAccount))
 
-	// Route for panic
+	// Route for panic, keep logging anyhow
 	router.PanicHandler = func(w http.ResponseWriter, r *http.Request, arg interface{}) {
-		http.Error(w, fmt.Sprint(arg), 500)
+		d := &responseData{
+			status: 0,
+			size:   0,
+		}
+		lrw := loggingResponseWriter{
+			ResponseWriter: w,
+			responseData:   d,
+		}
+		http.Error(&lrw, fmt.Sprint(arg), 500)
+		if hdl.Log {
+			Logger(r, d.status, d.size)
+		}
 	}
 
 	// Create server
@@ -93,6 +229,6 @@ func ServeApp(cfg Config) error {
 	}
 
 	// Serve app
-	logrus.Infoln("Serve shiori in", url)
+	logrus.Infoln("Serve shiori in", url, cfg.RootPath)
 	return svr.ListenAndServe()
 }