Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Terminable Middleware #147

Open
pjebs opened this issue Sep 20, 2016 · 19 comments
Open

Terminable Middleware #147

pjebs opened this issue Sep 20, 2016 · 19 comments

Comments

@pjebs
Copy link
Contributor

pjebs commented Sep 20, 2016

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
Copy link

yanfali commented Sep 20, 2016

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

@pjebs
Copy link
Contributor Author

pjebs commented Sep 20, 2016

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
Copy link

yanfali commented Sep 20, 2016

@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
Copy link

yanfali commented Sep 20, 2016

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
Copy link
Contributor Author

pjebs commented Sep 20, 2016

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
Copy link
Contributor

jszwedko commented Sep 24, 2016

@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
Copy link

yanfali commented Sep 24, 2016

@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
Copy link
Contributor Author

pjebs commented Sep 25, 2016

@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
Copy link
Contributor Author

pjebs commented Sep 25, 2016

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

@yanfali
Copy link

yanfali commented Sep 25, 2016

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 [email protected] 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
Copy link

yanfali commented Sep 25, 2016

This seems relevant golang/go#10958

On Sat, Sep 24, 2016, 18:02 Yan-Fa Li [email protected] 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 [email protected] 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
Copy link

yanfali commented Sep 25, 2016

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
Copy link

yanfali commented Sep 25, 2016

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
Copy link
Contributor Author

pjebs commented Sep 25, 2016

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

I'm now the one really confused.

@yanfali
Copy link

yanfali commented Sep 25, 2016

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

@pjebs
Copy link
Contributor Author

pjebs commented Sep 25, 2016

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
Copy link
Contributor Author

pjebs commented Sep 25, 2016

@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
Copy link

yanfali commented Jan 3, 2017

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

@pjebs
Copy link
Contributor Author

pjebs commented Jan 4, 2017

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

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

3 participants