Terminable Middleware

[pjebs]

I definitely think this should be implemented for Negroni.

Terminable middleware allows you to add code that runs AFTER the response has been fully served.

There is a subtle but crucial difference to adding code after next(rw, r).

It is also related (vaguely) to an issue I highlighted here: #138 (comment) where in the the recovery middleware, if you were to add a custom error handler, the handler wastes time from client's perspective.

Further Reading:
https://laravel.com/docs/5.3/middleware#terminable-middleware

[yanfali]

This isn't really a go problem. We have go routines. PHP doesn't.

[pjebs]

After the response is over, all currently-running goroutines will get shut down due to current implementation of negroni.

Terminable middleware happen outside of request-response cycle.

[yanfali]

@pjebs I was looking for how that works. Can you show me which file that happens in? I use websockets with negroni and hijack the connection and it keeps on running so I'm interested in how that works.

[yanfali]

I was asking how the handler shuts down all the go routines that were spawned while it was running. I didn't know you could so that without using channels. Would love to learn more.

[pjebs]

If it's not in the negroni code, it's because net/http 's built-in webserver shuts it down once the handler completes. In order for negroni to have terminable middleware, something external has to keep it running.

In Go, all goroutines will get shut down automatically if the code that called it returns. That's the default behaviour with go.

You can work around it by either preventing the caller from returning in the first place (i.e. using waitgroups etc) but that isn't a solution for negroni.

What negroni needs to do is itself call the middleware's terminate handler.

[jszwedko]

@pjebs can you clarify what you mean by

There is a subtle but crucial difference to adding code after next(rw, r)

I'm not sure I see the difference.

[yanfali]

@pjebs I'm sorry, but can you show me in the code where this is the case? I don't believe it works that way unless you specifically use something like "context" or write your go-routines to specifically listen to a channel. The only time this would happen is if the runtime exited, and in a server this would basically never happen unless you're shutting down or have crashed.

[pjebs]

@yanfali To test my claim: Add this to any negroni handler:

import (
    "time"
    "log"
)

//Inside a handler
go func() {
    for {
        log.Println(time.Now())
    }
}()
time.Sleep(5 * time.Second)

Add this to inside a negroni handler.
According to your model of Go/Negroni behaviour, since the goroutine goes for ever, the handler should never exit and it should keep logging the current time. (Or alternatively, if the handler does exit, the goroutine will persist and keep logging.)

According to my assertion, the handler is kept alive for 5 seconds. Whilst it is alive, the goroutine will keep logging for 5 seconds. After the handler returns after 5 seconds, the goroutine is shut down by net/http's webserver automatically.

[pjebs]

@jszwedko I'll create a proof of concept PR soon to explain.

[yanfali]

I'll give it a try. I'm wondering if your spammy go routine is being
punished by the scheduler for being too chatty. In a tight loop that would
consume a lot of run time.

On Sat, Sep 24, 2016, 17:54 pjebs notifications@github.com wrote:

@yanfali https://github.com/yanfali To test my claim: Add this to any
negroni handler:

import (
"time"
"log"
)

go func() {
for {
log.Println(time.Now())
}
}()
time.Sleep(5 * time.Second)

Add this to inside a negroni handler.
According to your model of Go/Negroni behaviour, since the goroutine goes
for ever, the handler should never exit and it should keep logging the
current time.

According to my assertion, the handler is kept alive for 5 seconds. The
goroutine will keep logging for 5 minutes only before the goroutine is shut
down by net/http's webserver.

—
You are receiving this because you were mentioned.

Reply to this email directly, view it on GitHub
#147 (comment), or mute
the thread
https://github.com/notifications/unsubscribe-auth/ACK5U0SiXu6MPIH1SiO4CTlce1wDHizxks5qtcY4gaJpZM4KBGpu
.

[yanfali]

This seems relevant golang/go#10958

On Sat, Sep 24, 2016, 18:02 Yan-Fa Li yanfali@gmail.com wrote:

I'll give it a try. I'm wondering if your spammy go routine is being
punished by the scheduler for being too chatty. In a tight loop that would
consume a lot of run time.

On Sat, Sep 24, 2016, 17:54 pjebs notifications@github.com wrote:

@yanfali https://github.com/yanfali To test my claim: Add this to any
negroni handler:

import (
"time"
"log"
)

go func() {
for {
log.Println(time.Now())
}
}()
time.Sleep(5 * time.Second)

Add this to inside a negroni handler.
According to your model of Go/Negroni behaviour, since the goroutine goes
for ever, the handler should never exit and it should keep logging the
current time.

According to my assertion, the handler is kept alive for 5 seconds. The
goroutine will keep logging for 5 minutes only before the goroutine is shut
down by net/http's webserver.

—
You are receiving this because you were mentioned.

Reply to this email directly, view it on GitHub
#147 (comment),
or mute the thread
https://github.com/notifications/unsubscribe-auth/ACK5U0SiXu6MPIH1SiO4CTlce1wDHizxks5qtcY4gaJpZM4KBGpu
.

[yanfali]

I just ran this for over 5 minutes, it's still going

package main

import (
    "log"
    "net/http"
    "time"
)

func main() {

    http.HandleFunc("/", func(w http.ResponseWriter, r *http.Request) {

        //Inside a handler
        go func() {
            for {
                log.Println(time.Now())
                time.Sleep(time.Millisecond * 100)
            }
        }()
        time.Sleep(5 * time.Second)
    })
    log.Fatal(http.ListenAndServe(":8080", nil))
}

I guess you're deadlocking the GC or the Scheduler because you're running it in a tight loop.

[yanfali]

This was on a linux AMD64 system with 16 real cores, 64G of RAM and 4.7 kernel. I have not tried this on windows or OSX. I used go 1.7.1 to compile this program.

[pjebs]

@yanfali I guess I learnt something. You proved me wrong!

I'm now the one really confused.

[yanfali]

I was actually genuinely interested that you had discovered something I didn't know, so we both learned something.

[pjebs]

From here: https://www.golang-book.com/books/intro/10

This is why the call to the Scanln function has been included; without it the program would exit before being given the opportunity to print all the numbers

This kind of thing when I first learnt Go is the source of my confusion. I'm really more confused now.

Do you see that sample code?

They put the Scanln at the end of main deliberately to stop the main function from returning so that the goroutines can complete.

The only way I can reconcile your discovery and the statement in that book (assuming it is true) is to assume it only applies to the main function.

[pjebs]

@jszwedko With @yanfali 's proof, which I've tested, we don't need terminable middleware. I will close this issue soon.

However, as per my concern in: #138 (comment),

the recovery middleware should definitely be changed to:

if rec.ErrorHandlerFunc != nil {
                go func() {
                    defer func() {
                        if err := recover(); err != nil {
                            rec.Logger.Printf("provided ErrorHandlerFunc panic'd: %s, trace:\n%s", err, debug.Stack())
                            rec.Logger.Printf("%s\n", debug.Stack())
                        }
                    }()
                    rec.ErrorHandlerFunc(err)
                }()
}

go func() { being the change

[yanfali]

@pjebs ping - probably ok to close this now right?

[pjebs]

Added a pull request: #165
Seems to work well.