create tests to cover when client closes request

[nbari]

If a client close the request and the router is configured to log requests the returned status is 499, like Nginx is doing it, for example:

package main

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

	"github.com/nbari/violetear"
)

func helloWorld(w http.ResponseWriter, r *http.Request) {
	time.Sleep(time.Second)
	w.Write([]byte("hello world"))
}

func main() {
	router := violetear.New()
	router.LogRequests = true
	router.HandleFunc("*", helloWorld)
	log.Fatal(http.ListenAndServe(":8080", router))
}

This is the output of some requests:

$ go run main.go
2017/10/07 14:58:11 Adding path: * [ALL]
2017/10/07 14:58:13 127.0.0.1:58916 [/] 200 11 1.000748552s
2017/10/07 14:58:16 127.0.0.1:58918 [/] 200 11 1.005227763s
2017/10/07 14:58:18 127.0.0.1:58920 [/] 499 11 1.001131965s

Notice the last entry, it returned a 499, in this case, the user closed the request (ctrl + c) after doing curl 0:8080

This is working but the tests are missing specific to cover this block https://github.com/nbari/violetear/blob/master/responsewriter.go#L24-L30

[asasmoyo]

let me try to work on this. any idea how can we simulate a ctrl + c?

[nbari]

Hi @asasmoyo, thanks.

Regarding the tests, probably with something like this:

timeout := time.Duration(time.Millisecond)
client := http.Client{
    Timeout: timeout,
}
client.Get(url)

[asasmoyo]

i just tried to use timeout on client. but i got timeout error instead, with nil response. so i can't assert the returned status code

[nbari]

And on the server side, you got a 499?

Check the other tests to get a better idea: https://github.com/nbari/violetear/blob/master/responsewriter_test.go#L161

[asasmoyo]

ah wait, i think i am missing something

[asasmoyo]

my bad, what i did was checking the response status on the client side. since it terminates the connection before server could reply something so it is make sense if resp is nil.

anyway, when i make the client to be timeout, the logger here https://github.com/nbari/violetear/blob/master/violetear.go#L264 does not get executed because h.ServerHTTP is panicking. is this expected?

[nbari]

No, first run the tests make test check if everything is working, later just run your server do some queries etc, if possible, please share your code in a gist in a way it can be reproduced

[nbari]

@asasmoyo I came out with this:

package main

import (
	"fmt"
	"net/http"
	"net/http/httptest"
	"time"

	"github.com/nbari/violetear"
)

func main() {
	router := violetear.New()
	router.Verbose = false
	router.LogRequests = true
	router.Logger = func(w *violetear.ResponseWriter, r *http.Request) {
		fmt.Printf("%d\n", w.Status())
	}
	router.HandleFunc("*", func(w http.ResponseWriter, r *http.Request) {
		time.Sleep(10 * time.Millisecond)
		w.Write([]byte("hello world"))
	})
	ts := httptest.NewServer(router)
	defer ts.Close()
	client := ts.Client()
	client.Timeout = time.Duration(time.Millisecond)
	client.Get(ts.URL)
}

Give a try it should not panic, and just print a 499

[asasmoyo]

great! i was thinking to create the test like this

func TestResponseWriterLogger499(t *testing.T) {
	var statusChan = make(chan int)

	router := New()
	router.Verbose = false
	router.LogRequests = true
	router.Logger = func(w *ResponseWriter, r *http.Request) {
		statusChan <- w.Status()
	}
	router.HandleFunc("*", func(w http.ResponseWriter, r *http.Request) {
		time.Sleep(10 * time.Millisecond)
	}, "GET")

	server := httptest.NewServer(router)
	defer server.Close()

	client := server.Client()
	client.Timeout = time.Millisecond
	client.Get(server.URL)

	code := <-statusChan
	expect(t, code, 499)
}

we can capture the returned status code using logger, but race condition may happens

[nbari]

Give a try to this: https://github.com/nbari/violetear/blob/master/responsewriter_test.go#L161-L177
I am curious about the "panics" you mention before, in theory, should not panic

[asasmoyo]

ah how stupid i am :D
using channel was bad idea, we can just assert the status in the logger

my bad, i have deleted the code which cause triggering panic. i believe i made a custom request with a cancel context in it. then canceling the request right after it is fired causing panic in https://github.com/nbari/violetear/blob/master/violetear.go#L260 and fires the panic handler. so logger does not get executed

[nbari]

That test covers only when using a custom logger but won't cover when no logger is enabled, in where the status code defaults to 200, so if you want you could do the test for the other cases, there are many scenarios that probably I am missing. Any help is more than welcome.

[asasmoyo]

sure, i'll see if i can do something

[nbari]

#14