diff --git a/auth/imap.go b/auth/imap.go index ca1bd0c..385962b 100644 --- a/auth/imap.go +++ b/auth/imap.go @@ -1,13 +1,12 @@ package auth import ( - "log" "net/http" + "github.com/rs/zerolog/log" + "github.com/emersion/go-imap/client" "github.com/emersion/go-sasl" - - "git.sr.ht/~sircmpwn/tokidoki/debug" ) type IMAPProvider struct { @@ -20,7 +19,7 @@ func NewIMAP(addr string, tls bool) AuthProvider { prov := &IMAPProvider{addr, tls} conn, err := prov.dial() if err != nil { - log.Fatalf("Error dialing configured IMAP auth server: %s", err.Error()) + log.Fatal().Err(err).Msg("error dialing configured IMAP auth server") } conn.Close() return prov @@ -45,7 +44,7 @@ func (prov *IMAPProvider) doAuth(next http.Handler, conn, err := prov.dial() if err != nil { - debug.Printf("Auth dial error: %v", err) + log.Debug().Err(err).Msg("auth dial error") http.Error(w, "Temporary authentication error, try again later", http.StatusServiceUnavailable) return } @@ -53,7 +52,7 @@ func (prov *IMAPProvider) doAuth(next http.Handler, auth := sasl.NewPlainClient("", user, pass) if err := conn.Authenticate(auth); err != nil { - debug.Printf("Auth error: %v", err) + log.Debug().Err(err).Msg("auth error") http.Error(w, "Invalid username or password", http.StatusUnauthorized) return } diff --git a/auth/pam.go b/auth/pam.go index bd94e12..c48818f 100644 --- a/auth/pam.go +++ b/auth/pam.go @@ -7,8 +7,7 @@ import ( "net/http" "github.com/msteinert/pam" - - "git.sr.ht/~sircmpwn/tokidoki/debug" + "github.com/rs/zerolog/log" ) type pamProvider struct{} @@ -34,7 +33,7 @@ func pamAuth(next http.Handler, w http.ResponseWriter, r *http.Request) { } t, err := pam.StartFunc("login", user, func(s pam.Style, msg string) (string, error) { - debug.Printf("%v %v", s, msg) + log.Debug().Str("style", fmt.Sprintf("%v", s)).Msg(msg) switch s { case pam.PromptEchoOff: return pass, nil @@ -45,26 +44,26 @@ func pamAuth(next http.Handler, w http.ResponseWriter, r *http.Request) { } }) if err != nil { - debug.Printf("Failed to start PAM conversation: %v", err) + log.Debug().Err(err).Msg("failed to start PAM conversation") http.Error(w, "Temporary authentication error, try again later", http.StatusServiceUnavailable) return } if err := t.Authenticate(0); err != nil { - debug.Printf("Auth error: %v", err) + log.Debug().Err(err).Msg("auth error") http.Error(w, "Invalid username or password", http.StatusUnauthorized) return } if err := t.AcctMgmt(0); err != nil { - debug.Printf("Account unavailable: %v", err) + log.Debug().Err(err).Msg("account unavailable") http.Error(w, "Account unavailable", http.StatusUnauthorized) return } user, err = t.GetItem(pam.User) if err != nil { - debug.Printf("Failed to get PAM username: %v", err) + log.Debug().Err(err).Msg("failed to get PAM username") http.Error(w, "Temporary authentication error, try again later", http.StatusServiceUnavailable) return } diff --git a/cmd/tokidoki/main.go b/cmd/tokidoki/main.go index 337e4dc..67b50a4 100644 --- a/cmd/tokidoki/main.go +++ b/cmd/tokidoki/main.go @@ -5,7 +5,6 @@ import ( "encoding/base64" "flag" "fmt" - "log" "net/http" "os" @@ -14,9 +13,10 @@ import ( "github.com/emersion/go-webdav/carddav" "github.com/go-chi/chi/v5" "github.com/go-chi/chi/v5/middleware" + "github.com/rs/zerolog" + "github.com/rs/zerolog/log" "git.sr.ht/~sircmpwn/tokidoki/auth" - "git.sr.ht/~sircmpwn/tokidoki/debug" "git.sr.ht/~sircmpwn/tokidoki/storage" ) @@ -85,12 +85,15 @@ func main() { var ( addr string authURL string + debug bool + jsonLog bool storageURL string ) flag.StringVar(&addr, "addr", ":8080", "listening address") flag.StringVar(&authURL, "auth.url", "", "auth backend URL (required)") flag.StringVar(&storageURL, "storage.url", "", "storage backend URL (required)") - flag.BoolVar(&debug.Enable, "debug", false, "enable debug output") + flag.BoolVar(&debug, "log.debug", false, "enable debug logs") + flag.BoolVar(&jsonLog, "log.json", false, "enable structured logs") flag.Parse() if len(flag.Args()) != 0 || authURL == "" || storageURL == "" { @@ -98,6 +101,15 @@ func main() { os.Exit(1) } + zerolog.TimeFieldFormat = zerolog.TimeFormatUnix + zerolog.SetGlobalLevel(zerolog.InfoLevel) + if debug { + zerolog.SetGlobalLevel(zerolog.DebugLevel) + } + if !jsonLog { + log.Logger = log.Output(zerolog.ConsoleWriter{Out: os.Stderr}) + } + for _, method := range []string{ "PROPFIND", "PROPPATCH", @@ -113,7 +125,7 @@ func main() { authProvider, err := auth.NewFromURL(authURL) if err != nil { - log.Fatalf("failed to load auth provider: %s", err.Error()) + log.Fatal().Err(err).Msg("failed to load auth provider") } mux.Use(authProvider.Middleware()) @@ -121,7 +133,7 @@ func main() { caldavBackend, carddavBackend, err := storage.NewFromURL(storageURL, "/calendar/", "/contacts/", upBackend) if err != nil { - log.Fatalf("failed to load storage backend: %s", err.Error()) + log.Fatal().Err(err).Msg("failed to load storage backend") } carddavHandler := carddav.Handler{Backend: carddavBackend} @@ -144,11 +156,11 @@ func main() { Handler: mux, } - log.Printf("Server running on %s", addr) - debug.Printf("Debug output enabled") + log.Info().Str("address", addr).Msg("starting server") + log.Debug().Msg("debug output enabled") err = server.ListenAndServe() if err != http.ErrServerClosed { - log.Fatalf("ListenAndServe: %s", err.Error()) + log.Fatal().Err(err).Msg("ListenAndServe() error") } } diff --git a/debug/debug.go b/debug/debug.go deleted file mode 100644 index 1d8f21f..0000000 --- a/debug/debug.go +++ /dev/null @@ -1,15 +0,0 @@ -package debug - -import ( - "log" -) - -var ( - Enable = false -) - -func Printf(format string, v ...any) { - if Enable { - log.Printf("[debug] "+format, v...) - } -} diff --git a/go.mod b/go.mod index af7737d..142d561 100644 --- a/go.mod +++ b/go.mod @@ -10,9 +10,13 @@ require ( github.com/emersion/go-webdav v0.3.2-0.20221122105813-ac9af45270fb github.com/go-chi/chi/v5 v5.0.7 github.com/msteinert/pam v1.0.0 + github.com/rs/zerolog v1.28.0 ) require ( + github.com/mattn/go-colorable v0.1.12 // indirect + github.com/mattn/go-isatty v0.0.14 // indirect github.com/teambition/rrule-go v1.7.2 // indirect + golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6 // indirect golang.org/x/text v0.3.7 // indirect ) diff --git a/go.sum b/go.sum index d604f6a..24be469 100644 --- a/go.sum +++ b/go.sum @@ -1,3 +1,4 @@ +github.com/coreos/go-systemd/v22 v22.3.3-0.20220203105225-a9a7ef127534/go.mod h1:Y58oyj3AT4RCenI/lSvhwexgC+NSVTIJ3seZv2GcEnc= github.com/emersion/go-ical v0.0.0-20220601085725-0864dccc089f h1:feGUUxxvOtWVOhTko8Cbmp33a+tU0IMZxMEmnkoAISQ= github.com/emersion/go-ical v0.0.0-20220601085725-0864dccc089f/go.mod h1:2MKFUgfNMULRxqZkadG1Vh44we3y5gJAtTBlVsx1BKQ= github.com/emersion/go-imap v1.2.0 h1:lyUQ3+EVM21/qbWE/4Ya5UG9r5+usDxlg4yfp3TgHFA= @@ -14,11 +15,22 @@ github.com/emersion/go-webdav v0.3.2-0.20221122105813-ac9af45270fb h1:hf7lieMeu2 github.com/emersion/go-webdav v0.3.2-0.20221122105813-ac9af45270fb/go.mod h1:lkPYZO/vsDNV9GPyVMBBsAUZzzxINL97bEVFykApo58= github.com/go-chi/chi/v5 v5.0.7 h1:rDTPXLDHGATaeHvVlLcR4Qe0zftYethFucbjVQ1PxU8= github.com/go-chi/chi/v5 v5.0.7/go.mod h1:DslCQbL2OYiznFReuXYUmQ2hGd1aDpCnlMNITLSKoi8= +github.com/godbus/dbus/v5 v5.0.4/go.mod h1:xhWf0FNVPg57R7Z0UbKHbJfkEywrmjJnf7w5xrFpKfA= +github.com/mattn/go-colorable v0.1.12 h1:jF+Du6AlPIjs2BiUiQlKOX0rt3SujHxPnksPKZbaA40= +github.com/mattn/go-colorable v0.1.12/go.mod h1:u5H1YNBxpqRaxsYJYSkiCWKzEfiAb1Gb520KVy5xxl4= +github.com/mattn/go-isatty v0.0.14 h1:yVuAays6BHfxijgZPzw+3Zlu5yQgKGP2/hcQbHb7S9Y= +github.com/mattn/go-isatty v0.0.14/go.mod h1:7GGIvUiUoEMVVmxf/4nioHXj79iQHKdU27kJ6hsGG94= github.com/msteinert/pam v1.0.0 h1:4XoXKtMCH3+e6GIkW41uxm6B37eYqci/DH3gzSq7ocg= github.com/msteinert/pam v1.0.0/go.mod h1:M4FPeAW8g2ITO68W8gACDz13NDJyOQM9IQsQhrR6TOI= +github.com/pkg/errors v0.9.1/go.mod h1:bwawxfHBFNV+L2hUp1rHADufV3IMtnDRdf1r5NINEl0= +github.com/rs/xid v1.4.0/go.mod h1:trrq9SKmegXys3aeAKXMUTdJsYXVwGY3RLcfgqegfbg= +github.com/rs/zerolog v1.28.0 h1:MirSo27VyNi7RJYP3078AA1+Cyzd2GB66qy3aUHvsWY= +github.com/rs/zerolog v1.28.0/go.mod h1:NILgTygv/Uej1ra5XxGf82ZFSLk58MFGAUS2o6usyD0= github.com/teambition/rrule-go v1.7.2 h1:goEajFWYydfCgavn2m/3w5U+1b3PGqPUHx/fFSVfTy0= github.com/teambition/rrule-go v1.7.2/go.mod h1:mBJ1Ht5uboJ6jexKdNUJg2NcwP8uUMNvStWXlJD3MvU= -golang.org/x/sys v0.0.0-20210615035016-665e8c7367d1 h1:SrN+KX8Art/Sf4HNj6Zcz06G7VEz+7w9tdXTPOZ7+l4= +golang.org/x/sys v0.0.0-20210630005230-0f9fa26af87c/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= +golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6 h1:foEbQz/B0Oz6YIqu/69kfXPYeFQAuuMYFkjaqXzl5Wo= +golang.org/x/sys v0.0.0-20210927094055-39ccf1dd6fa6/go.mod h1:oPkhp1MJrh7nUepCBck5+mAzfO9JrbApNNgaTdGDITg= golang.org/x/term v0.0.0-20210927222741-03fcf44c2211 h1:JGgROgKl9N8DuW20oFS5gxc+lE67/N3FcwmBPMe7ArY= golang.org/x/text v0.3.6/go.mod h1:5Zoc/QRtKVWzQhOtBMvqHzDpF6irO9z98xDceosuGiQ= golang.org/x/text v0.3.7 h1:olpwvP2KacW1ZWvsR7uQhoyTYvKAupfQrRGBFM352Gk= diff --git a/storage/filesystem.go b/storage/filesystem.go index 21aa8be..2f34959 100644 --- a/storage/filesystem.go +++ b/storage/filesystem.go @@ -11,11 +11,11 @@ import ( "regexp" "strings" + "github.com/rs/zerolog/log" + "github.com/emersion/go-webdav" "github.com/emersion/go-webdav/caldav" "github.com/emersion/go-webdav/carddav" - - "git.sr.ht/~sircmpwn/tokidoki/debug" ) type filesystemBackend struct { @@ -83,7 +83,7 @@ func (b *filesystemBackend) safeLocalPath(homeSetPath string, urlPath string) (s } // only accept simple file names for now if !validFilenameRegex.MatchString(file) { - debug.Printf("%s does not match regex!\n", file) + log.Debug().Str("file", file).Msg("file name does not match regex") err := fmt.Errorf("invalid file name: %s", file) return "", webdav.NewHTTPError(400, err) } diff --git a/storage/filesystem_caldav.go b/storage/filesystem_caldav.go index 6da1a4b..193cd2a 100644 --- a/storage/filesystem_caldav.go +++ b/storage/filesystem_caldav.go @@ -12,11 +12,11 @@ import ( "path" "path/filepath" + "github.com/rs/zerolog/log" + "github.com/emersion/go-ical" "github.com/emersion/go-webdav" "github.com/emersion/go-webdav/caldav" - - "git.sr.ht/~sircmpwn/tokidoki/debug" ) func (b *filesystemBackend) CalendarHomeSetPath(ctx context.Context) (string, error) { @@ -100,7 +100,7 @@ func (b *filesystemBackend) loadAllCalendars(ctx context.Context, propFilter []s return nil }) - debug.Printf("filesystem.loadAllCalendars() returning %d results from %s", len(result), localPath) + log.Debug().Int("results", len(result)).Str("path", localPath).Msg("filesystem.loadAllCalendars() successful") return result, err } @@ -124,7 +124,7 @@ func createDefaultCalendar(path, localPath string) error { } func (b *filesystemBackend) Calendar(ctx context.Context) (*caldav.Calendar, error) { - debug.Printf("filesystem.Calendar()") + log.Debug().Msg("filesystem.Calendar()") localPath, err := b.localCalDAVPath(ctx, "") if err != nil { @@ -132,7 +132,7 @@ func (b *filesystemBackend) Calendar(ctx context.Context) (*caldav.Calendar, err } localPath = filepath.Join(localPath, "calendar.json") - debug.Printf("loading calendar from %s", localPath) + log.Debug().Str("local_path", localPath).Msg("loading calendar") data, readErr := ioutil.ReadFile(localPath) if os.IsNotExist(readErr) { @@ -141,7 +141,7 @@ func (b *filesystemBackend) Calendar(ctx context.Context) (*caldav.Calendar, err return nil, err } urlPath = path.Join(urlPath, defaultResourceName) + "/" - debug.Printf("creating default calendar (URL:path): %s:%s", urlPath, localPath) + log.Debug().Str("local_path", localPath).Str("url_path", urlPath).Msg("creating calendar") err = createDefaultCalendar(urlPath, localPath) if err != nil { return nil, err @@ -161,7 +161,7 @@ func (b *filesystemBackend) Calendar(ctx context.Context) (*caldav.Calendar, err } func (b *filesystemBackend) GetCalendarObject(ctx context.Context, objPath string, req *caldav.CalendarCompRequest) (*caldav.CalendarObject, error) { - debug.Printf("filesystem.GetCalendarObject(%s, %v)", objPath, req) + log.Debug().Str("url_path", objPath).Msg("filesystem.GetCalendarObject()") localPath, err := b.localCalDAVPath(ctx, objPath) if err != nil { @@ -171,7 +171,7 @@ func (b *filesystemBackend) GetCalendarObject(ctx context.Context, objPath strin info, err := os.Stat(localPath) if err != nil { if errors.Is(err, fs.ErrNotExist) { - debug.Printf("not found: %s", localPath) + log.Debug().Str("local_path", localPath).Msg("object not found") return nil, webdav.NewHTTPError(404, err) } return nil, err @@ -184,7 +184,7 @@ func (b *filesystemBackend) GetCalendarObject(ctx context.Context, objPath strin calendar, err := calendarFromFile(localPath, propFilter) if err != nil { - debug.Printf("error reading calendar: %v", err) + log.Debug().Err(err).Msg("error reading calendar") return nil, err } @@ -204,7 +204,7 @@ func (b *filesystemBackend) GetCalendarObject(ctx context.Context, objPath strin } func (b *filesystemBackend) ListCalendarObjects(ctx context.Context, req *caldav.CalendarCompRequest) ([]caldav.CalendarObject, error) { - debug.Printf("filesystem.ListCalendarObjects(%v)", req) + log.Debug().Msg("filesystem.ListCalendarObjects()") var propFilter []string if req != nil && !req.AllProps { @@ -215,7 +215,7 @@ func (b *filesystemBackend) ListCalendarObjects(ctx context.Context, req *caldav } func (b *filesystemBackend) QueryCalendarObjects(ctx context.Context, query *caldav.CalendarQuery) ([]caldav.CalendarObject, error) { - debug.Printf("filesystem.QueryCalendarObjects(%v)", query) + log.Debug().Msg("filesystem.QueryCalendarObjects()") var propFilter []string if query != nil && !query.CompRequest.AllProps { @@ -231,7 +231,7 @@ func (b *filesystemBackend) QueryCalendarObjects(ctx context.Context, query *cal } func (b *filesystemBackend) PutCalendarObject(ctx context.Context, objPath string, calendar *ical.Calendar, opts *caldav.PutCalendarObjectOptions) (loc string, err error) { - debug.Printf("filesystem.PutCalendarObject(%s, %v, %v)", objPath, calendar, opts) + log.Debug().Str("url_path", objPath).Msg("filesystem.PutCalendarObject()") _, uid, err := caldav.ValidateCalendarObject(calendar) if err != nil { @@ -289,7 +289,7 @@ func (b *filesystemBackend) PutCalendarObject(ctx context.Context, objPath strin } func (b *filesystemBackend) DeleteCalendarObject(ctx context.Context, path string) error { - debug.Printf("filesystem.DeleteCalendarObject(%s)", path) + log.Debug().Str("url_path", path).Msg("filesystem.DeleteCalendarObject()") localPath, err := b.localCalDAVPath(ctx, path) if err != nil { diff --git a/storage/filesystem_carddav.go b/storage/filesystem_carddav.go index 0736922..257456c 100644 --- a/storage/filesystem_carddav.go +++ b/storage/filesystem_carddav.go @@ -12,11 +12,11 @@ import ( "path" "path/filepath" + "github.com/rs/zerolog/log" + "github.com/emersion/go-vcard" "github.com/emersion/go-webdav" "github.com/emersion/go-webdav/carddav" - - "git.sr.ht/~sircmpwn/tokidoki/debug" ) func (b *filesystemBackend) AddressbookHomeSetPath(ctx context.Context) (string, error) { @@ -95,14 +95,14 @@ func createDefaultAddressBook(path, localPath string) error { } func (b *filesystemBackend) AddressBook(ctx context.Context) (*carddav.AddressBook, error) { - debug.Printf("filesystem.AddressBook()") + log.Debug().Msg("filesystem.AddressBook()") localPath, err := b.localCardDAVPath(ctx, "") if err != nil { return nil, err } localPath = filepath.Join(localPath, "addressbook.json") - debug.Printf("loading addressbook from %s", localPath) + log.Debug().Str("local_path", localPath).Msg("loading addressbook") data, readErr := ioutil.ReadFile(localPath) if os.IsNotExist(readErr) { @@ -111,7 +111,7 @@ func (b *filesystemBackend) AddressBook(ctx context.Context) (*carddav.AddressBo return nil, err } urlPath = path.Join(urlPath, defaultResourceName) + "/" - debug.Printf("creating default addressbook (URL:path): %s:%s", urlPath, localPath) + log.Debug().Str("local_path", localPath).Str("url_path", urlPath).Msg("creating addressbook") err = createDefaultAddressBook(urlPath, localPath) if err != nil { return nil, err @@ -131,7 +131,7 @@ func (b *filesystemBackend) AddressBook(ctx context.Context) (*carddav.AddressBo } func (b *filesystemBackend) GetAddressObject(ctx context.Context, objPath string, req *carddav.AddressDataRequest) (*carddav.AddressObject, error) { - debug.Printf("filesystem.GetAddressObject(%s, %v)", objPath, req) + log.Debug().Str("url_path", objPath).Msg("filesystem.GetAddressObject()") localPath, err := b.localCardDAVPath(ctx, objPath) if err != nil { return nil, err @@ -213,12 +213,12 @@ func (b *filesystemBackend) loadAllContacts(ctx context.Context, propFilter []st return nil }) - debug.Printf("filesystem.loadAllContacts() returning %d results from %s", len(result), localPath) + log.Debug().Int("results", len(result)).Str("path", localPath).Msg("filesystem.loadAllContacts() successful") return result, err } func (b *filesystemBackend) ListAddressObjects(ctx context.Context, req *carddav.AddressDataRequest) ([]carddav.AddressObject, error) { - debug.Printf("filesystem.ListAddressObjects(%v)", req) + log.Debug().Msg("filesystem.ListAddressObjects()") var propFilter []string if req != nil && !req.AllProp { propFilter = req.Props @@ -228,7 +228,7 @@ func (b *filesystemBackend) ListAddressObjects(ctx context.Context, req *carddav } func (b *filesystemBackend) QueryAddressObjects(ctx context.Context, query *carddav.AddressBookQuery) ([]carddav.AddressObject, error) { - debug.Printf("filesystem.QueryAddressObjects(%v)", query) + log.Debug().Msg("filesystem.QueryAddressObjects()") var propFilter []string if query != nil && !query.DataRequest.AllProp { propFilter = query.DataRequest.Props @@ -243,7 +243,7 @@ func (b *filesystemBackend) QueryAddressObjects(ctx context.Context, query *card } func (b *filesystemBackend) PutAddressObject(ctx context.Context, objPath string, card vcard.Card, opts *carddav.PutAddressObjectOptions) (loc string, err error) { - debug.Printf("filesystem.PutAddressObject(%v, %v, %v)", objPath, card, opts) + log.Debug().Str("url_path", objPath).Msg("filesystem.PutAddressObject()") // Object always get saved as .vcf dirname, _ := path.Split(objPath) @@ -296,7 +296,7 @@ func (b *filesystemBackend) PutAddressObject(ctx context.Context, objPath string } func (b *filesystemBackend) DeleteAddressObject(ctx context.Context, path string) error { - debug.Printf("filesystem.DeleteAddressObject(%s)", path) + log.Debug().Str("url_path", path).Msg("filesystem.DeleteAddressObject()") localPath, err := b.localCardDAVPath(ctx, path) if err != nil {