2

Main Purpose: I want to simply count the execution time for any API / route, and add it into the Response Header with key: ExecutionTime.

I am very open to another alternative, since my method may wrong as I am still new in Go-Echo framework.

What I have been doing: So this is my middleware code:

func (s *Stats) ExecTime(next echo.HandlerFunc) echo.HandlerFunc {
    return func(c echo.Context) error {
        c.Response().Header().Set("ExecutionStartedAt", time.Now().String())
        if err := next(c); err != nil { //exec main process
            c.Error(err)
        }
        c.Response().Header().Set("ExecutionDoneAt", time.Now().String())
        return nil
    }
}

Current Result:

< HTTP/1.1 200 OK
< Content-Type: application/json; charset=UTF-8
< Executionstartedat: 2022-09-11 16:32:15.612045 +0700 WIB m=+3.619364986
< Server: Echo/3.0
< Date: Sun, 11 Sep 2022 09:32:21 GMT
< Content-Length: 856

Please note: There is an Executionstartedat added. But unfortunatelly there is no ExecutionDoneAt as expected.

Expected Result:

< HTTP/1.1 200 OK
< Content-Type: application/json; charset=UTF-8
< Executionstartedat: 2022-09-11 16:32:15.612045 +0700 WIB m=+3.619364986
< Executiondoneat: 2022-09-11 16:32:18.612045 +0700 WIB m=+3.619364986
< Server: Echo/3.0
< Date: Sun, 11 Sep 2022 09:32:21 GMT
< Content-Length: 856

I am following this documentation: https://echo.labstack.com/cookbook/middleware/#response

Any help, any idea, any alternative ways to accomplish same result would be very very appreciated. Thank you very much.

Edited #1:

What else I have tried:

I have tried to use another middleware, the timing is good, just as I expected. But unfortunately the header is still empty.

    e.Use(middleware.BodyDump(func(c echo.Context, reqBody, resBody []byte) {
        fmt.Println("this is from BodyDump 7: ", time.Now())
        c.Response().Header().Set("ExecutionTime7", "Exec Time: " + time.Now().String())
    }))

The result is exactly like above, no change at all.

Edited #2

here is the working code example:

// ExecTime is the middleware function.
func (s *Stats) ExecTime(next echo.HandlerFunc) echo.HandlerFunc {
    return func(c echo.Context) error {
        before := time.Now()
        c.Response().Header().Set("ExecutionStartedAt", before.String())

        c.Response().Before(func() {
            after := time.Now()
            elapsed := time.Since(before)

            c.Response().Header().Set("ExecutionDoneAt", after.String())
            c.Response().Header().Set("ExecutionTime", elapsed.String())
        })

        if err := next(c); err != nil { //exec main process
            c.Error(err)
        }
        return nil
    }
}
Jacky Supit
  • 469
  • 3
  • 15
  • In HTTP headers go before the body, as the name "header" implies. So once you write the body you cannot write the header. You may try using HTTP/2 Trailers. Or execute the process, but before writing its output to the body, calculate the execution time, add the header, and then write the body. – mkopriva Sep 11 '22 at 09:45
  • oh wait, this your statement: "once you write the body you cannot write the header" That explain everything. Thank you. so now I need to find a way about how to cut the process before its writing to the body. I hope we can do that with a middleware. – Jacky Supit Sep 11 '22 at 10:00
  • 1
    I don't use `echo` so I don't know what the correct approach is, but it seems to me like it'd be better if you use the response [before hook](https://echo.labstack.com/guide/response/#hooks). – mkopriva Sep 11 '22 at 10:05
  • thank you so much for the clue. Will go there now. – Jacky Supit Sep 11 '22 at 10:13
  • 1
    The only way to do this is to buffer the entire body in memory (or maybe on disk if it's large), calculate your time, write the header, then write the buffered body to the network. If you have any large responses, or rely on streaming, this has some serious drawbacks. – Jonathan Hall Sep 11 '22 at 10:16
  • 1
    You might consider whether using an HTTP Trailer would work for you... it's an often ignored feature of HTTP. – Jonathan Hall Sep 11 '22 at 10:17
  • @mkopriva OMG!! It works!!! Thank you so much. Would you post your comment as an answer? I will pick it as accepted answer. – Jacky Supit Sep 11 '22 at 10:22

1 Answers1

3

In HTTP the headers go before the body, as the name "header" implies. So once you write the body you cannot write the header. You may try using HTTP/2 Trailers. Or execute the process, but before writing its output to the body, calculate the execution time, add the header, and then write the body.

I don't use echo so I don't know what the correct approach is, but it seems to me like it'd be better if you use the response before hook.

Example by @JackySupit:

// ExecTime is the middleware function.
func (s *Stats) ExecTime(next echo.HandlerFunc) echo.HandlerFunc {
    return func(c echo.Context) error {
        before := time.Now()
        c.Response().Header().Set("ExecutionStartedAt", before.String())

        c.Response().Before(func() {
            after := time.Now()
            elapsed := time.Since(before)

            c.Response().Header().Set("ExecutionDoneAt", after.String())
            c.Response().Header().Set("ExecutionTime", elapsed.String())
        })

        if err := next(c); err != nil { //exec main process
            c.Error(err)
        }
        return nil
    }
}
mkopriva
  • 35,176
  • 4
  • 57
  • 71
  • thanks man, you saved my 8 hours finding this problem :) oh and I have edited you answer, by adding the working example code. please approve, might be useful for others. – Jacky Supit Sep 11 '22 at 10:26