Go: log/return

Hoje eu quero falar sobre algo que tive muita duvida no começo e hoje ainda me incomoda quando vejo. Quando estamos construindo um aplicativo é necessário gerenciar erros e reporta-los de alguma forma.

Imagine que você tem um handler e ele receba parâmetros de paginação:

package main

import (
	"fmt"
	"log"
	"net/http"
	"os"
	"strconv"
	"strings"
)

const defaultPageSize = 10

func list(w http.ResponseWriter, r *http.Request) error {
	page := 0
	size := defaultPageSize

	if p := strings.TrimSpace(r.FormValue("page")); p != "" {
		pint, err := strconv.Atoi(p)
		if err != nil {
			http.Error(w, "Oops something went wrong", http.StatusBadRequest)
			return err
		}
		page = pint
	}
	if s := strings.TrimSpace(r.FormValue("size")); s != "" {
		sint, err := strconv.Atoi(s)
		if err != nil {
			http.Error(w, "Oops something went wrong", http.StatusBadRequest)
			return err
		}
		size = sint
	}

	fmt.Fprintf(w, "offset: %d\n", page*size)

	return nil
}

func errWrapper(handler func(w http.ResponseWriter, r *http.Request) error) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		err := handler(w, r)
		if err != nil {
			log.Println("ERROR:", err)
		}
	})
}

func main() {

	port := os.Getenv("PORT")
	if port == "" {
		port = ":3000"
	}

	http.Handle("/", errWrapper(list))

	log.Printf("app at http://localhost%s\n", port)
	if err := http.ListenAndServe(port, nil); err != nil {
		log.Fatalf("abrupt stop of app: %v", err)
	}

}

Provavelmente você pode começar com algo assim, apenas retornando o erro que pode ocorrer no strconv. Depois de alguns testes você repara que não consegue saber de qual strconv surge o problema, temos duas conversões e elas retornam a mesma mensagem. Algumas pessoas vão sugerir inserir uma mensagem de log onde ocorre o problema.

package main

import (
	"fmt"
	"log"
	"net/http"
	"os"
	"strconv"
	"strings"
)

const defaultPageSize = 10

func list(w http.ResponseWriter, r *http.Request) error {
	page := 0
	size := defaultPageSize

	if p := strings.TrimSpace(r.FormValue("page")); p != "" {
		pint, err := strconv.Atoi(p)
		if err != nil {
			log.Printf("list; cannot convert page to int: %v\n", err)
			http.Error(w, "Oops something went wrong", http.StatusBadRequest)
			return err
		}
		page = pint
	}
	if s := strings.TrimSpace(r.FormValue("size")); s != "" {
		sint, err := strconv.Atoi(s)
		if err != nil {
			log.Printf("list; cannot convert size to int: %v\n", err)
			http.Error(w, "Oops something went wrong", http.StatusBadRequest)
			return err
		}
		size = sint
	}

	fmt.Fprintf(w, "offset: %d\n", page*size)

	return nil
}

func errWrapper(handler func(w http.ResponseWriter, r *http.Request) error) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		err := handler(w, r)
		if err != nil {
			log.Println("ERROR:", err)
		}
	})
}

func main() {

	port := os.Getenv("PORT")
	if port == "" {
		port = ":3000"
	}

	http.Handle("/", errWrapper(list))

	log.Printf("app at http://localhost%s\n", port)
	if err := http.ListenAndServe(port, nil); err != nil {
		log.Fatalf("abrupt stop of app: %v", err)
	}

}

Corrige o problema, mas agora você tem duas mensagens passando informações semelhantes. A saída da aplicação ficaria assim:

list; cannot convert size to int: strconv.Atoi: parsing "10,": invalid syntax
ERROR: strconv.Atoi: parsing "10,": invalid syntax

Parece um custo pequeno no começo o ganho de uma linha extra, mas as coisas vão se acumulando com o tempo. Passa um mês e você + equipe já colocaram log em cada erro possível. Linhas que não contribuem diretamente com a lógica necessária para se atingir o objetivo desejado são consideradas ruído. Aqui nós temos ruído para o programador que vai realizar a manutenção do código e para a parte de sustentação que as vezes precisa identificar rapidamente um problema e vai encontrar linhas “duplicadas”.

Uma das formas de mitigar o problema é seguir uma regra de quando devemos enriquecer a mensagem de erro ou não. A mensagem de log que utilizamos acima enriquece sem tocar no erro, mas podemos fazer isso diretamente, eliminando assim a necessidade do log.

package main

import (
	"fmt"
	"log"
	"net/http"
	"os"
	"strconv"
	"strings"
)

const defaultPageSize = 10

func list(w http.ResponseWriter, r *http.Request) error {
	page := 0
	size := defaultPageSize

	if p := strings.TrimSpace(r.FormValue("page")); p != "" {
		pint, err := strconv.Atoi(p)
		if err != nil {
			http.Error(w, "Oops something went wrong", http.StatusBadRequest)
			return fmt.Errorf("list; cannot convert page to int: %w", err)
		}
		page = pint
	}
	if s := strings.TrimSpace(r.FormValue("size")); s != "" {
		sint, err := strconv.Atoi(s)
		if err != nil {
			http.Error(w, "Oops something went wrong", http.StatusBadRequest)
			return fmt.Errorf("list; cannot convert size to int: %w", err)
		}
		size = sint
	}

	fmt.Fprintf(w, "offset: %d\n", page*size)

	return nil
}

func errWrapper(handler func(w http.ResponseWriter, r *http.Request) error) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		err := handler(w, r)
		if err != nil {
			log.Println("ERROR:", err)
		}
	})
}

func main() {

	port := os.Getenv("PORT")
	if port == "" {
		port = ":3000"
	}

	http.Handle("/", errWrapper(list))

	log.Printf("app at http://localhost%s\n", port)
	if err := http.ListenAndServe(port, nil); err != nil {
		log.Fatalf("abrupt stop of app: %v", err)
	}

}

E a nossa saída:

ERROR: list; cannot convert size to int: strconv.Atoi: parsing "10,": invalid syntax

Menos ruído, mais informação e temos uma noção de onde ocorreu o problema no código. O ideal agora era saber exatamente onde ocorreu o problema através de uma stack trace.

package main

import (
	"fmt"
	"log"
	"net/http"
	"os"
	"strconv"
	"strings"

	"github.com/pkg/errors"
)

const defaultPageSize = 10

func list(w http.ResponseWriter, r *http.Request) error {
	page := 0
	size := defaultPageSize

	if p := strings.TrimSpace(r.FormValue("page")); p != "" {
		pint, err := strconv.Atoi(p)
		if err != nil {
			http.Error(w, "Oops something went wrong", http.StatusBadRequest)
			return errors.Wrap(err, "cannot convert page to int")
		}
		page = pint
	}
	if s := strings.TrimSpace(r.FormValue("size")); s != "" {
		sint, err := strconv.Atoi(s)
		if err != nil {
			http.Error(w, "Oops something went wrong", http.StatusBadRequest)
			return errors.Wrap(err, "cannot convert page to int")
		}
		size = sint
	}

	fmt.Fprintf(w, "offset: %d\n", page*size)

	return nil
}

func errWrapper(handler func(w http.ResponseWriter, r *http.Request) error) http.Handler {
	return http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
		err := handler(w, r)
		if err != nil {
			log.Printf("ERROR: %+v\n", err)
		}
	})
}

func main() {

	port := os.Getenv("PORT")
	if port == "" {
		port = ":3000"
	}

	http.Handle("/", errWrapper(list))

	log.Printf("app at http://localhost%s\n", port)
	if err := http.ListenAndServe(port, nil); err != nil {
		log.Fatalf("abrupt stop of app: %v", err)
	}

}

Saída com stack trace:

ERROR: strconv.Atoi: parsing "10,": invalid syntax
cannot convert page to int
main.list
        C:/Users/CLIENTE/Documents/code/go/logreturn/main.go:32
main.errWrapper.func1
        C:/Users/CLIENTE/Documents/code/go/logreturn/main.go:44
net/http.HandlerFunc.ServeHTTP
        c:/go/src/net/http/server.go:2012
net/http.(*ServeMux).ServeHTTP
        c:/go/src/net/http/server.go:2387
net/http.serverHandler.ServeHTTP
        c:/go/src/net/http/server.go:2807
net/http.(*conn).serve
        c:/go/src/net/http/server.go:1895
runtime.goexit
        c:/go/src/runtime/asm_amd64.s:1373

Assim nem precisamos mais colocar o nome do handler na mensagem de erro (list), já que o mesmo vai ser exibido e identificado o arquivo:linha onde ocorreu o primeiro erro na cadeia.

Temos toda informação necessária para avaliar/depurar nossos problemas sem adicionar muito ruído ao projeto inicial. Existe uma boa prática no uso do pacote errors que pode ser encontrada nessa postagem do Dave Cheney. Recomendo d+ seguir esse blog.

Dia produtivo de verdade é aquele que você remove 300 linhas no balanço liquido e mantendo a mesma funcionalidade. Recentemente tive um dia desses só corrigindo error/log handling como escrevi acima. Abraços

Deixe um comentário

Preencha os seus dados abaixo ou clique em um ícone para log in:

Logotipo do WordPress.com

Você está comentando utilizando sua conta WordPress.com. Sair /  Alterar )

Foto do Google

Você está comentando utilizando sua conta Google. Sair /  Alterar )

Imagem do Twitter

Você está comentando utilizando sua conta Twitter. Sair /  Alterar )

Foto do Facebook

Você está comentando utilizando sua conta Facebook. Sair /  Alterar )

Conectando a %s