revendor with lateas auth lib, sets logger to stdout

backend/Gopkg.lock

@@ -113,17 +113,18 @@
 
 [[projects]]
   branch = "master"
-  digest = "1:b117a0a0b46dad26254a48c11a511d6c697038e591a1d7ce11a229e1c8e0a237"
+  digest = "1:9240838c072f500013fa68b709050692dd6ba0095131046639618a296d4f4400"
   name = "github.com/go-pkgz/auth"
   packages = [
     ".",
     "avatar",
+    "logger",
     "middleware",
     "provider",
     "token",
   ]
   pruneopts = "UT"
-  revision = "b95cb645615503dba4d5fced3b77d97d4f0dcc81"
+  revision = "c322626ae89af60b2ad5a8f96ade761b5ed361bb"
 
 [[projects]]
   digest = "1:1212e114344a5cdcc834ea69e19d456eef230f9784659080fee67e02ba2cb574"

backend/app/cmd/server.go

@@ -17,6 +17,7 @@ import (
 
 	"github.com/go-pkgz/auth"
 	"github.com/go-pkgz/auth/avatar"
+	"github.com/go-pkgz/auth/logger"
 	"github.com/go-pkgz/auth/provider"
 	"github.com/go-pkgz/auth/token"
 	"github.com/go-pkgz/mongo"
@@ -269,13 +270,13 @@ func (s *ServerCommand) newServerApp() (*serverApp, error) {
 
 	srv.ScoreThresholds.Low, srv.ScoreThresholds.Critical = s.LowScore, s.CriticalScore
 
-	var devAuth provider.DevAuthServer
+	var devAuth *provider.DevAuthServer
 	if s.Auth.Dev {
-		p, err := authenticator.Provider("dev")
+		da, err := authenticator.DevAuth()
 		if err != nil {
-			return nil, errors.Wrap(err, "can't pick dev provider")
+			return nil, errors.Wrap(err, "can't make dev oauth2 server")
 		}
-		devAuth = provider.DevAuthServer{Provider: p}
+		devAuth = da
 	}
 
 	return &serverApp{
@@ -283,7 +284,7 @@ func (s *ServerCommand) newServerApp() (*serverApp, error) {
 		restSrv:       srv,
 		migratorSrv:   migr,
 		exporter:      exporter,
-		devAuth:       &devAuth,
+		devAuth:       devAuth,
 		dataService:   dataService,
 		avatarStore:   avatarStore,
 		notifyService: notifyService,
@@ -316,7 +317,7 @@ func (a *serverApp) run(ctx context.Context) error {
 	}()
 	a.activateBackup(ctx) // runs in goroutine for each site
 	if a.Auth.Dev {
-		go a.devAuth.Run() // dev oauth2 server on :8084
+		go a.devAuth.Run(context.Background()) // dev oauth2 server on :8084
 	}
 	a.restSrv.Run(a.Port)
 	close(a.terminated)
@@ -547,6 +548,7 @@ func (s *ServerCommand) makeAuthenticator(ds *service.DataStore, avas avatar.Sto
 		AvatarStore:       avas,
 		AvatarResizeLimit: s.Avatar.RszLmt,
 		AvatarRoutePath:   "/api/v1/avatar",
+		Logger:            logger.Std,
 	})
 	s.addAuthProviders(authenticator)
 	return authenticator

backend/vendor/github.com/go-pkgz/auth/README.md

@@ -33,8 +33,8 @@ func main() {
 		SecretReader: token.SecretFunc(func(id string) (string, error) { // secret key for JWT
 			return "secret", nil
 		}),
-		TokenDuration:  time.Hour,
-		CookieDuration: time.Hour * 24,
+		TokenDuration:  time.Minute * 5, // token expires in 5 minutes
+		CookieDuration: time.Hour * 24,  // cookie expires in 1 day and will enforce re-login
 		Issuer:         "my-test-app",
 		URL:            "http://127.0.0.1:8080",
 		AvatarStore:    avatar.NewLocalFS("/tmp"),
@@ -170,7 +170,18 @@ It will run fake aouth2 "server" on port :8084 and user could login with any use
 
 _Warning: this is not the real oauth2 server but just a small fake thing for development and testing only. Don't use `dev` provider with any production code._
 
-    
+### Other ways to authenticate
+
+In addition to the primary method (i.e. JWT cookie with XSRF header) there are two more ways to authenticate:
+
+1. Send JWT header as `X-JWT`. This shouldn't be used for web application, however can be helpful for service-to-service authentication.
+2. [Basic access authentication](https://en.wikipedia.org/wiki/Basic_access_authentication). This mode by default disabled and will be enabled it `Opts.AdminPasswd` defined. This will allow access with basic auth admin:<Opts.AdminPasswd> with user [admin](https://github.com/go-pkgz/auth/blob/master/middleware/auth.go#L24). Such method can be used for automation scripts.
+
+### Logging
+
+By default this library doesn't print anything to stdout/stderr, however user can pass a logger implementing `logger.L` interface with a single method `Logf(format string, args ...interface{})`. Functional adapter for this interface included as `logger.Func`. There are two predefined implementations in the `logger` package - `NoOp` (prints nothing, default) and `Std` wrapping `log.Printf` from stdlib.
+
+
 ## Register oauth2 providers
 
 Authentication handled by external providers. You should setup oauth2 for all (or some) of them to allow users to authenticate. It is not mandatory to have all of them, but at least one should be correctly configured.

backend/vendor/github.com/go-pkgz/auth/auth.go

@@ -10,6 +10,7 @@ import (
 	"github.com/pkg/errors"
 
 	"github.com/go-pkgz/auth/avatar"
+	"github.com/go-pkgz/auth/logger"
 	"github.com/go-pkgz/auth/middleware"
 	"github.com/go-pkgz/auth/provider"
 	"github.com/go-pkgz/auth/token"
@@ -17,6 +18,7 @@ import (
 
 // Service provides higher level wrapper allowing to construct everything and get back token middleware
 type Service struct {
+	logger         logger.L
 	opts           Opts
 	jwtService     *token.Service
 	providers      []provider.Service
@@ -49,11 +51,30 @@ type Opts struct {
 	AvatarResizeLimit int          // resize avatar's limit in pixels
 	AvatarRoutePath   string       // avatar routing prefix, i.e. "/api/v1/avatar", default `/avatar`
 
-	AdminPasswd string // if presented, allows basic auth with user admin and given password
+	AdminPasswd string   // if presented, allows basic auth with user admin and given password
+	Logger      logger.L // logger interface, default is no logging at all
 }
 
 // NewService initializes everything
-func NewService(opts Opts) *Service {
+func NewService(opts Opts) (res *Service) {
+
+	res = &Service{
+		opts:   opts,
+		logger: opts.Logger,
+		authMiddleware: middleware.Authenticator{
+			Validator:   opts.Validator,
+			AdminPasswd: opts.AdminPasswd,
+		},
+		issuer: opts.Issuer,
+	}
+
+	if opts.Issuer == "" {
+		res.issuer = "go-pkgz/auth"
+	}
+
+	if opts.Logger == nil {
+		res.logger = logger.Func(func(fmt string, args ...interface{}) {}) // do-nothing logger
+	}
 
 	jwtService := token.NewService(token.Opts{
 		SecretReader:   opts.SecretReader,
@@ -66,28 +87,19 @@ func NewService(opts Opts) *Service {
 		JWTHeaderKey:   opts.JWTHeaderKey,
 		XSRFCookieName: opts.XSRFCookieName,
 		XSRFHeaderKey:  opts.XSRFHeaderKey,
-		Issuer:         opts.Issuer,
+		Issuer:         res.issuer,
 	})
 
 	if opts.SecretReader == nil {
 		jwtService.SecretReader = token.SecretFunc(func(id string) (string, error) {
 			return "", errors.New("secrets reader not available")
 		})
+		res.logger.Logf("[WARN] no secret reader defined")
 	}
 
-	res := Service{
-		opts:       opts,
-		jwtService: jwtService,
-		authMiddleware: middleware.Authenticator{
-			JWTService:  jwtService,
-			Validator:   opts.Validator,
-			AdminPasswd: opts.AdminPasswd,
-		},
-	}
-
-	if opts.Issuer == "" {
-		res.issuer = "go-pkgz/auth"
-	}
+	res.jwtService = jwtService
+	res.authMiddleware.JWTService = jwtService
+	res.authMiddleware.L = res.logger
 
 	if opts.AvatarStore != nil {
 		res.avatarProxy = &avatar.Proxy{
@@ -95,13 +107,14 @@ func NewService(opts Opts) *Service {
 			URL:         opts.URL,
 			RoutePath:   opts.AvatarRoutePath,
 			ResizeLimit: opts.AvatarResizeLimit,
+			L:           res.logger,
 		}
 		if res.avatarProxy.RoutePath == "" {
 			res.avatarProxy.RoutePath = "/avatar"
 		}
 	}
 
-	return &res
+	return res
 }
 
 // Handlers gets http.Handler for all providers and avatars
@@ -171,6 +184,7 @@ func (s *Service) AddProvider(name string, cid string, csecret string) {
 		AvatarSaver: s.avatarProxy,
 		Cid:         cid,
 		Csecret:     csecret,
+		L:           s.logger,
 	}
 
 	switch strings.ToLower(name) {
@@ -191,6 +205,16 @@ func (s *Service) AddProvider(name string, cid string, csecret string) {
 	s.authMiddleware.Providers = s.providers
 }
 
+// DevAuth makes dev oauth2 server, for testing and development only!
+func (s *Service) DevAuth() (*provider.DevAuthServer, error) {
+	p, err := s.Provider("dev") // peak dev provider
+	if err != nil {
+		return nil, errors.Wrap(err, "dev provider not registered")
+	}
+	// make and start dev auth server
+	return &provider.DevAuthServer{Provider: p, L: s.logger}, nil
+}
+
 // Provider gets provider by name
 func (s *Service) Provider(name string) (provider.Service, error) {
 	for _, p := range s.providers {

backend/vendor/github.com/go-pkgz/auth/avatar/avatar.go

@@ -7,7 +7,6 @@ import (
 	"image"
 	"image/png"
 	"io"
-	"log"
 	"net/http"
 	"strconv"
 	"strings"
@@ -17,12 +16,14 @@ import (
 	"github.com/pkg/errors"
 	"golang.org/x/image/draw"
 
+	"github.com/go-pkgz/auth/logger"
 	"github.com/go-pkgz/auth/token"
 )
 
 // Proxy provides http handler for avatars from avatar.Store
 // On user login token will call Put and it will retrieve and save picture locally.
 type Proxy struct {
+	logger.L
 	Store       Store
 	RoutePath   string
 	URL         string
@@ -51,7 +52,7 @@ func (p *Proxy) Put(u token.User) (avatarURL string, err error) {
 
 	defer func() {
 		if e := resp.Body.Close(); e != nil {
-			log.Printf("[WARN] can't close response body, %s", e)
+			p.Logf("[WARN] can't close response body, %s", e)
 		}
 	}()
 
@@ -64,7 +65,7 @@ func (p *Proxy) Put(u token.User) (avatarURL string, err error) {
 		return "", err
 	}
 
-	log.Printf("[DEBUG] saved avatar from %s to %s, user %q", u.Picture, avatarID, u.Name)
+	p.Logf("[DEBUG] saved avatar from %s to %s, user %q", u.Picture, avatarID, u.Name)
 	return p.URL + p.RoutePath + "/" + avatarID, nil
 }
 
@@ -97,7 +98,7 @@ func (p *Proxy) Handler(w http.ResponseWriter, r *http.Request) {
 
 	defer func() {
 		if e := avReader.Close(); e != nil {
-			log.Printf("[WARN] can't close avatar reader for %s, %s", avatarID, e)
+			p.Logf("[WARN] can't close avatar reader for %s, %s", avatarID, e)
 		}
 	}()
 
@@ -105,7 +106,7 @@ func (p *Proxy) Handler(w http.ResponseWriter, r *http.Request) {
 	w.Header().Set("Content-Length", strconv.Itoa(size))
 	w.WriteHeader(http.StatusOK)
 	if _, err = io.Copy(w, avReader); err != nil {
-		log.Printf("[WARN] can't send response to %s, %s", r.RemoteAddr, err)
+		p.Logf("[WARN] can't send response to %s, %s", r.RemoteAddr, err)
 	}
 }
 
@@ -114,11 +115,11 @@ func (p *Proxy) Handler(w http.ResponseWriter, r *http.Request) {
 // Returns original reader if resizing is not needed or failed.
 func (p *Proxy) resize(reader io.Reader, limit int) io.Reader {
 	if reader == nil {
-		log.Print("[WARN] avatar resize(): reader is nil")
+		p.Logf("[WARN] avatar resize(): reader is nil")
 		return nil
 	}
 	if limit <= 0 {
-		log.Print("[DEBUG] avatar resize(): limit should be greater than 0")
+		p.Logf("[DEBUG] avatar resize(): limit should be greater than 0")
 		return reader
 	}
 
@@ -126,14 +127,14 @@ func (p *Proxy) resize(reader io.Reader, limit int) io.Reader {
 	tee := io.TeeReader(reader, &teeBuf)
 	src, _, err := image.Decode(tee)
 	if err != nil {
-		log.Printf("[WARN] avatar resize(): can't decode avatar image, %s", err)
+		p.Logf("[WARN] avatar resize(): can't decode avatar image, %s", err)
 		return &teeBuf
 	}
 
 	bounds := src.Bounds()
 	w, h := bounds.Dx(), bounds.Dy()
 	if w <= limit && h <= limit || w <= 0 || h <= 0 {
-		log.Print("[DEBUG] resizing image is smaller that the limit or has 0 size")
+		p.Logf("[DEBUG] resizing image is smaller that the limit or has 0 size")
 		return &teeBuf
 	}
 	newW, newH := w*limit/h, limit
@@ -146,7 +147,7 @@ func (p *Proxy) resize(reader io.Reader, limit int) io.Reader {
 
 	var out bytes.Buffer
 	if err = png.Encode(&out, m); err != nil {
-		log.Printf("[WARN] avatar resize(): can't encode resized avatar to PNG, %s", err)
+		p.Logf("[WARN] avatar resize(): can't encode resized avatar to PNG, %s", err)
 		return &teeBuf
 	}
 	return &out

backend/vendor/github.com/go-pkgz/auth/avatar/localfs.go

@@ -4,7 +4,6 @@ import (
 	"fmt"
 	"hash/crc64"
 	"io"
-	"log"
 	"os"
 	"path"
 	"path/filepath"
@@ -47,14 +46,13 @@ func (fs *LocalFS) Put(userID string, reader io.Reader) (avatar string, err erro
 	}
 	defer func() {
 		if e := fh.Close(); e != nil {
-			log.Printf("[WARN] can't close avatar file %s, %s", avFile, e)
+			err = errors.Wrapf(err, "can't close avatar file %s", avFile)
 		}
 	}()
 
 	if _, err = io.Copy(fh, reader); err != nil {
 		return "", errors.Wrapf(err, "can't save file %s", avFile)
 	}
-	log.Printf("[DEBUG] put avatar for %s to %s completed", userID, fh.Name())
 	return id + imgSfx, nil
 }
 
@@ -78,7 +76,6 @@ func (fs *LocalFS) ID(avatar string) (id string) {
 	avFile := path.Join(location, avatar)
 	fi, err := os.Stat(avFile)
 	if err != nil {
-		log.Printf("[DEBUG] can't get file info '%s', %s", avFile, err)
 		return encodeID(avatar)
 	}
 	return encodeID(avatar + strconv.FormatInt(fi.ModTime().Unix(), 10))

backend/vendor/github.com/go-pkgz/auth/logger/logger.go

@@ -0,0 +1,20 @@
+package logger
+
+import "log"
+
+// L defines minimal interface used to log things
+type L interface {
+	Logf(format string, args ...interface{})
+}
+
+// Func type is an adapter to allow the use of ordinary functions as Logger.
+type Func func(format string, args ...interface{})
+
+// Logf calls f(id)
+func (f Func) Logf(format string, args ...interface{}) { f(format, args...) }
+
+// NoOp logger
+var NoOp = Func(func(format string, args ...interface{}) {})
+
+// Std logger
+var Std = Func(func(format string, args ...interface{}) { log.Printf(format, args...) })

backend/vendor/github.com/go-pkgz/auth/middleware/auth.go

@@ -3,18 +3,19 @@ package middleware
 
 import (
 	"encoding/base64"
-	"log"
 	"net/http"
 	"strings"
 
 	"github.com/pkg/errors"
 
+	"github.com/go-pkgz/auth/logger"
 	"github.com/go-pkgz/auth/provider"
 	"github.com/go-pkgz/auth/token"
 )
 
 // Authenticator is top level auth object providing middlewares
 type Authenticator struct {
+	logger.L
 	JWTService  *token.Service
 	Providers   []provider.Service
 	Validator   token.Validator
@@ -50,7 +51,7 @@ func (a *Authenticator) auth(reqAuth bool) func(http.Handler) http.Handler {
 			h.ServeHTTP(w, r)
 			return
 		}
-		log.Printf("[DEBUG] auth failed, %s", err)
+		a.Logf("[DEBUG] auth failed, %s", err)
 		http.Error(w, "Unauthorized", http.StatusUnauthorized)
 	}
 
@@ -94,7 +95,7 @@ func (a *Authenticator) auth(reqAuth bool) func(http.Handler) http.Handler {
 						onError(h, w, r, errors.Wrap(err, "can't refresh token"))
 						return
 					}
-					log.Printf("[DEBUG] token refreshed for %+v", claims.User)
+					a.Logf("[DEBUG] token refreshed for %+v", claims.User)
 				}
 
 				r = token.SetUserInfo(r, *claims.User) // populate user info to request context
@@ -150,18 +151,18 @@ func (a *Authenticator) basicAdminUser(r *http.Request) bool {
 
 	b, err := base64.StdEncoding.DecodeString(s[1])
 	if err != nil {
-		log.Printf("[WARN] admin user auth failed, can't to decode %s, %s", s[1], err)
+		a.Logf("[WARN] admin user auth failed, can't to decode %s, %s", s[1], err)
 		return false
 	}
 
 	pair := strings.SplitN(string(b), ":", 2)
 	if len(pair) != 2 {
-		log.Printf("[WARN] admin user auth failed, can't split basic auth %s", string(b))
+		a.Logf("[WARN] admin user auth failed, can't split basic auth %s", string(b))
 		return false
 	}
 
 	if pair[0] != "admin" || pair[1] != a.AdminPasswd {
-		log.Printf("[WARN] dev user auth failed, user/passwd mismatch %+v", pair)
+		a.Logf("[WARN] admin basic auth failed, user/passwd mismatch %+v", pair)
 		return false
 	}
 

backend/vendor/github.com/go-pkgz/auth/provider/dev_provider.go

@@ -4,7 +4,6 @@ import (
 	"bytes"
 	"context"
 	"fmt"
-	"log"
 	"net/http"
 	"strings"
 	"sync"
@@ -15,6 +14,7 @@ import (
 	"github.com/pkg/errors"
 	"golang.org/x/oauth2"
 
+	"github.com/go-pkgz/auth/logger"
 	"github.com/go-pkgz/auth/token"
 )
 
@@ -26,10 +26,10 @@ const devAuthPort = 8084
 // can run in interactive and non-interactive mode. In interactive mode login attempts will show login form to select
 // desired user name, this is the mode used for development. Non-interactive mode for tests only.
 type DevAuthServer struct {
+	logger.L
 	Provider  Service
 	Automatic bool
-
-	username string // unsafe, but fine for dev
+	username  string // unsafe, but fine for dev
 
 	iconGen    *identicon.Generator
 	httpServer *http.Server
@@ -37,26 +37,26 @@ type DevAuthServer struct {
 }
 
 // Run oauth2 dev server on port devAuthPort
-func (d *DevAuthServer) Run() {
+func (d *DevAuthServer) Run(ctx context.Context) {
 	d.username = "dev_user"
-	log.Printf("[INFO] run local oauth2 dev server on %d, redir url=%s", devAuthPort, d.Provider.RedirectURL)
+	d.Logf("[INFO] run local oauth2 dev server on %d, redir url=%s", devAuthPort, d.Provider.RedirectURL)
 	d.lock.Lock()
 	var err error
 	d.iconGen, err = identicon.New("github", 5, 3)
 	if err != nil {
-		log.Printf("[WARN] can't create identicon, %s", err)
+		d.Logf("[WARN] can't create identicon, %s", err)
 	}
 
 	userFormTmpl, err := template.New("page").Parse(devUserFormTmpl)
 	if err != nil {
-		log.Printf("[WARN] can't parse user form template, %s", err)
+		d.Logf("[WARN] can't parse user form template, %s", err)
 		return
 	}
 
 	d.httpServer = &http.Server{
 		Addr: fmt.Sprintf(":%d", devAuthPort),
 		Handler: http.HandlerFunc(func(w http.ResponseWriter, r *http.Request) {
-			log.Printf("[DEBUG] dev oauth request %s %s %+v", r.Method, r.URL, r.Header)
+			d.Logf("[DEBUG] dev oauth request %s %s %+v", r.Method, r.URL, r.Header)
 			switch {
 
 			case strings.HasPrefix(r.URL.Path, "/login/oauth/authorize"):
@@ -67,7 +67,7 @@ func (d *DevAuthServer) Run() {
 					formData := struct{ Query string }{Query: r.URL.RawQuery}
 
 					if err = userFormTmpl.Execute(w, formData); err != nil {
-						log.Printf("[WARN] can't write, %s", err)
+						d.Logf("[WARN] can't write, %s", err)
 					}
 					return
 				}
@@ -78,7 +78,7 @@ func (d *DevAuthServer) Run() {
 
 				state := r.URL.Query().Get("state")
 				callbackURL := fmt.Sprintf("%s?code=g0ZGZmNjVmOWI&state=%s", d.Provider.RedirectURL, state)
-				log.Printf("[DEBUG] callback url=%s", callbackURL)
+				d.Logf("[DEBUG] callback url=%s", callbackURL)
 				w.Header().Add("Location", callbackURL)
 				w.WriteHeader(http.StatusFound)
 
@@ -131,21 +131,21 @@ func (d *DevAuthServer) Run() {
 	d.lock.Unlock()
 
 	err = d.httpServer.ListenAndServe()
-	log.Printf("[WARN] dev oauth2 server terminated, %s", err)
+	d.Logf("[WARN] dev oauth2 server terminated, %s", err)
 }
 
 // Shutdown oauth2 dev server
 func (d *DevAuthServer) Shutdown() {
-	log.Print("[WARN] shutdown oauth2 dev server")
+	d.Logf("[WARN] shutdown oauth2 dev server")
 	ctx, cancel := context.WithTimeout(context.Background(), time.Second)
 	defer cancel()
 	d.lock.Lock()
 	if d.httpServer != nil {
 		if err := d.httpServer.Shutdown(ctx); err != nil {
-			log.Printf("[DEBUG] oauth2 dev shutdown error, %s", err)
+			d.Logf("[DEBUG] oauth2 dev shutdown error, %s", err)
 		}
 	}
-	log.Print("[DEBUG] shutdown dev oauth2 server completed")
+	d.Logf("[DEBUG] shutdown dev oauth2 server completed")
 	d.lock.Unlock()
 }
 

backend/vendor/github.com/go-pkgz/auth/provider/service.go

@@ -7,11 +7,12 @@ import (
 	"encoding/json"
 	"fmt"
 	"io/ioutil"
-	"log"
 	"net/http"
 	"strings"
 	"time"
 
+	"github.com/go-pkgz/auth/logger"
+
 	jwt "github.com/dgrijalva/jwt-go"
 	"github.com/go-pkgz/rest"
 	"github.com/pkg/errors"
@@ -34,6 +35,7 @@ type Service struct {
 
 // Params to make initialized and ready to use provider
 type Params struct {
+	logger.L
 	URL         string
 	JwtService  *token.Service
 	AvatarSaver AvatarSaver
@@ -59,7 +61,10 @@ func (u userData) value(key string) string {
 
 // initService makes oauth2 service for given provider
 func initService(p Params, service Service) Service {
-	log.Printf("[INFO] init oauth2 service %s", service.Name)
+	if p.L == nil {
+		p.L = logger.Func(func(fmt string, args ...interface{}) {})
+	}
+	p.Logf("[INFO] init oauth2 service %s", service.Name)
 	service.Params = p
 	service.conf = oauth2.Config{
 		ClientID:     service.Cid,
@@ -69,7 +74,7 @@ func initService(p Params, service Service) Service {
 		Endpoint:     service.Endpoint,
 	}
 
-	log.Printf("[DEBUG] created %s oauth2, id=%s, redir=%s, endpoint=%s",
+	p.Logf("[DEBUG] created %s oauth2, id=%s, redir=%s, endpoint=%s",
 		service.Name, service.Cid, service.Endpoint, service.RedirectURL)
 	return service
 }
@@ -99,7 +104,7 @@ func (p Service) Handler(w http.ResponseWriter, r *http.Request) {
 // loginHandler - GET /login?from=redirect-back-url&site=siteID&session=1
 func (p Service) loginHandler(w http.ResponseWriter, r *http.Request) {
 
-	log.Printf("[DEBUG] login with %s", p.Name)
+	p.Logf("[DEBUG] login with %s", p.Name)
 	// make state (random) and store in session
 	state, err := p.randToken()
 	if err != nil {
@@ -134,7 +139,7 @@ func (p Service) loginHandler(w http.ResponseWriter, r *http.Request) {
 
 	// return login url
 	loginURL := p.conf.AuthCodeURL(state)
-	log.Printf("[DEBUG] login url %s, claims=%+v", loginURL, claims)
+	p.Logf("[DEBUG] login url %s, claims=%+v", loginURL, claims)
 
 	http.Redirect(w, r, loginURL, http.StatusFound)
 }
@@ -159,7 +164,7 @@ func (p Service) authHandler(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	log.Printf("[DEBUG] token with state %s", retrievedState)
+	p.Logf("[DEBUG] token with state %s", retrievedState)
 	tok, err := p.conf.Exchange(context.Background(), r.URL.Query().Get("code"))
 	if err != nil {
 		rest.SendErrorJSON(w, r, http.StatusInternalServerError, err, "exchange failed")
@@ -175,7 +180,7 @@ func (p Service) authHandler(w http.ResponseWriter, r *http.Request) {
 
 	defer func() {
 		if e := uinfo.Body.Close(); e != nil {
-			log.Printf("[WARN] failed to close response body, %s", e)
+			p.Logf("[WARN] failed to close response body, %s", e)
 		}
 	}()
 
@@ -190,7 +195,7 @@ func (p Service) authHandler(w http.ResponseWriter, r *http.Request) {
 		rest.SendErrorJSON(w, r, http.StatusInternalServerError, err, "failed to unmarshal user info")
 		return
 	}
-	log.Printf("[DEBUG] got raw user info %+v", jData)
+	p.Logf("[DEBUG] got raw user info %+v", jData)
 
 	u := p.MapUser(jData, data)
 	u = p.setAvatar(u)
@@ -215,7 +220,7 @@ func (p Service) authHandler(w http.ResponseWriter, r *http.Request) {
 		return
 	}
 
-	log.Printf("[DEBUG] user info %+v", u)
+	p.Logf("[DEBUG] user info %+v", u)
 
 	// redirect to back url if presented in login query params
 	if oauthClaims.Handshake != nil && oauthClaims.Handshake.From != "" {
@@ -231,7 +236,7 @@ func (p Service) setAvatar(u token.User) token.User {
 		if avatarURL, e := p.AvatarSaver.Put(u); e == nil {
 			u.Picture = avatarURL
 		} else {
-			log.Printf("[WARN] failed to set avatar for %+v, %+v", u, e)
+			p.Logf("[WARN] failed to set avatar for %+v, %+v", u, e)
 		}
 	}
 	return u