diff --git a/db.go b/db.go
index c125cd0..e4036a9 100644
--- a/db.go
+++ b/db.go
@@ -5,6 +5,8 @@ import (
"gorm.io/driver/sqlite"
"gorm.io/gorm"
+
+ logger "git.site.quack-lab.dev/dave/cylogger"
)
type DB interface {
@@ -25,9 +27,11 @@ func GetDB() (DB, error) {
var err error
if db != nil {
+ logger.Debug("Returning existing database connection")
return db, nil
}
+ logger.Debug("Creating new database connection to %s", options.DBPath)
dbFile := filepath.Join(options.DBPath)
db, err := gorm.Open(sqlite.Open(dbFile), &gorm.Config{
// SkipDefaultTransaction: true,
@@ -35,9 +39,11 @@ func GetDB() (DB, error) {
// Logger: gormlogger.Default.LogMode(gormlogger.Silent),
})
if err != nil {
+ logger.Error("Failed to open database: %v", err)
return nil, err
}
+ logger.Info("Database connection established successfully")
return &DBWrapper{db: db}, nil
}
@@ -51,18 +57,35 @@ func (db *DBWrapper) DB() *gorm.DB {
}
func (db *DBWrapper) GetTokenForCharacter(characterName string) (*Token, error) {
+ logger.Debug("Fetching token for character %s from database", characterName)
var token Token
err := db.db.Where("character_name = ?", characterName).First(&token).Error
if err != nil {
+ logger.Debug("No token found for character %s: %v", characterName, err)
return nil, err
}
+ logger.Debug("Token found for character %s, expires at %v", characterName, token.ExpiresAt)
return &token, nil
}
func (db *DBWrapper) SaveTokenForCharacter(token *Token) error {
- return db.db.Save(token).Error
+ logger.Debug("Saving token for character %s to database", token.CharacterName)
+ err := db.db.Save(token).Error
+ if err != nil {
+ logger.Error("Failed to save token for character %s: %v", token.CharacterName, err)
+ return err
+ }
+ logger.Debug("Token saved successfully for character %s", token.CharacterName)
+ return nil
}
func (db *DBWrapper) AutoMigrate(dst ...interface{}) error {
- return db.db.AutoMigrate(dst...)
+ logger.Debug("Running database auto-migration")
+ err := db.db.AutoMigrate(dst...)
+ if err != nil {
+ logger.Error("Database auto-migration failed: %v", err)
+ return err
+ }
+ logger.Debug("Database auto-migration completed successfully")
+ return nil
}
diff --git a/esi_sso.go b/esi_sso.go
index 5e12c41..a8e6bbb 100644
--- a/esi_sso.go
+++ b/esi_sso.go
@@ -18,6 +18,8 @@ import (
"time"
"gorm.io/gorm"
+
+ logger "git.site.quack-lab.dev/dave/cylogger"
)
const (
@@ -52,8 +54,11 @@ type SSO struct {
// NewSSO creates a new SSO instance
func NewSSO(clientID, redirectURI string, scopes []string) (*SSO, error) {
+ logger.Info("Creating new SSO instance for clientID %s with redirectURI %s and scopes %v", clientID, redirectURI, scopes)
+
db, err := GetDB()
if err != nil {
+ logger.Error("Failed to get database connection %v", err)
return nil, err
}
@@ -65,20 +70,30 @@ func NewSSO(clientID, redirectURI string, scopes []string) (*SSO, error) {
}
if err := s.initDB(); err != nil {
+ logger.Error("Failed to initialize SSO database %v", err)
return nil, err
}
+ logger.Info("SSO instance created successfully")
return s, nil
}
func (s *SSO) initDB() error {
- return s.db.AutoMigrate(&Token{})
+ logger.Debug("Initializing SSO database schema")
+ err := s.db.AutoMigrate(&Token{})
+ if err != nil {
+ logger.Error("Failed to migrate Token table %v", err)
+ return err
+ }
+ logger.Debug("SSO database schema initialized successfully")
+ return nil
}
// GetToken returns a valid access token for the given character name
// If no token exists, it will start the OAuth flow
// If token is expired, it will refresh it automatically
func (s *SSO) GetToken(ctx context.Context, characterName string) (string, error) {
+ logger.Debug("Getting token for character %s", characterName)
s.mu.Lock()
defer s.mu.Unlock()
@@ -86,42 +101,63 @@ func (s *SSO) GetToken(ctx context.Context, characterName string) (string, error
token, err := s.db.GetTokenForCharacter(characterName)
if err != nil {
if errors.Is(err, gorm.ErrRecordNotFound) {
+ logger.Info("No existing token found for character %s, starting authentication flow", characterName)
// No token exists, need to authenticate
if err := s.startAuthFlow(ctx, characterName); err != nil {
+ logger.Error("Authentication flow failed for character %s: %v", characterName, err)
return "", err
}
// After authentication, fetch the token from DB
token, err = s.db.GetTokenForCharacter(characterName)
if err != nil {
+ logger.Error("Failed to fetch token after authentication for character %s: %v", characterName, err)
return "", err
}
+ logger.Info("Successfully authenticated character %s", characterName)
} else {
+ logger.Error("Database error when fetching token for character %s: %v", characterName, err)
return "", err
}
+ } else {
+ logger.Debug("Found existing token for character %s, expires at %v", characterName, token.ExpiresAt)
}
// Check if token needs refresh
if time.Now().After(token.ExpiresAt.Add(-60 * time.Second)) {
+ logger.Info("Token for character %s is expired or expiring soon, refreshing", characterName)
if err := s.refreshToken(ctx, token); err != nil {
+ logger.Warning("Token refresh failed for character %s, re-authenticating: %v", characterName, err)
// Refresh failed, need to re-authenticate
if err := s.startAuthFlow(ctx, characterName); err != nil {
+ logger.Error("Re-authentication failed for character %s: %v", characterName, err)
return "", err
}
// After re-authentication, fetch the token from DB
token, err = s.db.GetTokenForCharacter(characterName)
if err != nil {
+ logger.Error("Failed to fetch token after re-authentication for character %s: %v", characterName, err)
return "", err
}
+ logger.Info("Successfully re-authenticated character %s", characterName)
+ } else {
+ logger.Debug("Token refreshed successfully for character %s", characterName)
}
+ } else {
+ logger.Debug("Token for character %s is still valid", characterName)
}
+ logger.Debug("Returning valid token for character %s", characterName)
return token.AccessToken, nil
}
func (s *SSO) startAuthFlow(ctx context.Context, characterName string) error {
+ logger.Info("Starting authentication flow for character %s", characterName)
+
// Generate PKCE
+ logger.Debug("Generating PKCE parameters")
verifier, challenge, err := generatePKCE()
if err != nil {
+ logger.Error("Failed to generate PKCE parameters: %v", err)
return err
}
@@ -133,36 +169,51 @@ func (s *SSO) startAuthFlow(ctx context.Context, characterName string) error {
}, 1)
authURL := s.buildAuthURL(challenge, s.state)
- fmt.Printf("Please visit this URL to authenticate:\n%s\n", authURL)
- fmt.Println("Waiting for authentication...")
+ logger.Info("Generated authentication URL for character %s", characterName)
+ logger.Info("Please visit this URL to authenticate: \n%s", authURL)
+ logger.Info("Waiting for authentication...")
// Start callback server
+ logger.Debug("Starting callback server")
server, err := s.startCallbackServer()
if err != nil {
+ logger.Error("Failed to start callback server: %v", err)
return err
}
s.server = server
defer server.Shutdown(ctx)
// Wait for callback
+ logger.Debug("Waiting for authentication callback")
code, receivedState, err := s.waitForCallback()
if err != nil {
+ logger.Error("Callback wait failed: %v", err)
return err
}
if receivedState != s.state {
+ logger.Error("Invalid state parameter received: %s, expected: %s", receivedState, s.state)
return errors.New("invalid state parameter")
}
+ logger.Debug("Received valid callback, exchanging code for token")
// Exchange code for token
token, err := s.exchangeCodeForToken(ctx, code, verifier)
if err != nil {
+ logger.Error("Failed to exchange code for token: %v", err)
return err
}
// Save token to DB
token.CharacterName = characterName
- return s.db.SaveTokenForCharacter(token)
+ logger.Debug("Saving token to database for character %s", characterName)
+ if err := s.db.SaveTokenForCharacter(token); err != nil {
+ logger.Error("Failed to save token to database: %v", err)
+ return err
+ }
+
+ logger.Info("Authentication flow completed successfully for character %s", characterName)
+ return nil
}
func (s *SSO) buildAuthURL(challenge, state string) string {
@@ -181,11 +232,14 @@ func (s *SSO) buildAuthURL(challenge, state string) string {
}
func (s *SSO) startCallbackServer() (*http.Server, error) {
+ logger.Debug("Starting callback server for redirect URI: %s", s.redirectURI)
u, err := url.Parse(s.redirectURI)
if err != nil {
+ logger.Error("Failed to parse redirect URI: %v", err)
return nil, err
}
if u.Scheme != "http" && u.Scheme != "https" {
+ logger.Error("Invalid redirect URI scheme: %s", u.Scheme)
return nil, errors.New("redirect URI must be http(s)")
}
hostPort := u.Host
@@ -197,9 +251,12 @@ func (s *SSO) startCallbackServer() (*http.Server, error) {
}
}
+ logger.Debug("Callback server will listen on %s", hostPort)
mux := http.NewServeMux()
mux.HandleFunc(u.Path, func(w http.ResponseWriter, r *http.Request) {
+ logger.Debug("Received callback request: %s %s", r.Method, r.URL.String())
if r.Method != http.MethodGet {
+ logger.Warning("Invalid callback method: %s", r.Method)
w.WriteHeader(http.StatusMethodNotAllowed)
s.callbackChan <- struct {
code string
@@ -212,7 +269,7 @@ func (s *SSO) startCallbackServer() (*http.Server, error) {
code := q.Get("code")
st := q.Get("state")
if code == "" || st == "" || st != s.state {
- fmt.Printf("Invalid SSO response: code=%s, state=%s, expected_state=%s\n", code, st, s.state)
+ logger.Error("Invalid SSO response: code=%s, state=%s, expected_state=%s", code, st, s.state)
w.WriteHeader(http.StatusBadRequest)
_, _ = w.Write([]byte("Invalid SSO response"))
s.callbackChan <- struct {
@@ -222,7 +279,7 @@ func (s *SSO) startCallbackServer() (*http.Server, error) {
}{"", "", errors.New("invalid state")}
return
}
- fmt.Printf("Exchanging token for code: %s\n", code)
+ logger.Info("Received valid callback, exchanging token for code: %s", code)
w.Header().Set("Content-Type", "text/html")
_, _ = w.Write([]byte("Login successful!
You can close this window.
"))
s.callbackChan <- struct {
@@ -238,25 +295,37 @@ func (s *SSO) startCallbackServer() (*http.Server, error) {
ln, err := net.Listen("tcp", hostPort)
if err != nil {
+ logger.Error("Failed to listen on %s: %v", hostPort, err)
return nil, err
}
server := &http.Server{Handler: mux}
- go func() { _ = server.Serve(ln) }()
+ go func() {
+ logger.Debug("Callback server started successfully")
+ _ = server.Serve(ln)
+ }()
return server, nil
}
func (s *SSO) waitForCallback() (code, state string, err error) {
+ logger.Debug("Waiting for authentication callback (timeout: 30s)")
// Wait for callback through channel
select {
case result := <-s.callbackChan:
+ if result.err != nil {
+ logger.Error("Callback received with error: %v", result.err)
+ return "", "", result.err
+ }
+ logger.Debug("Callback received successfully")
return result.code, result.state, result.err
case <-time.After(30 * time.Second):
+ logger.Error("Callback timeout after 30 seconds")
return "", "", errors.New("callback timeout")
}
}
func (s *SSO) exchangeCodeForToken(ctx context.Context, code, verifier string) (*Token, error) {
+ logger.Debug("Exchanging authorization code for access token")
form := url.Values{}
form.Set("grant_type", "authorization_code")
form.Set("code", code)
@@ -265,28 +334,34 @@ func (s *SSO) exchangeCodeForToken(ctx context.Context, code, verifier string) (
req, err := http.NewRequestWithContext(ctx, http.MethodPost, issuerTokenURL, strings.NewReader(form.Encode()))
if err != nil {
+ logger.Error("Failed to create token exchange request: %v", err)
return nil, err
}
req.Header.Set("Content-Type", "application/x-www-form-urlencoded")
+ logger.Debug("Sending token exchange request to %s", issuerTokenURL)
resp, err := http.DefaultClient.Do(req)
if err != nil {
+ logger.Error("Token exchange request failed: %v", err)
return nil, err
}
defer resp.Body.Close()
if resp.StatusCode < 200 || resp.StatusCode >= 300 {
b, _ := io.ReadAll(resp.Body)
+ logger.Error("Token exchange failed with status %d: %s", resp.StatusCode, string(b))
return nil, fmt.Errorf("token exchange failed: %s: %s", resp.Status, string(b))
}
var tr tokenResponse
if err := json.NewDecoder(resp.Body).Decode(&tr); err != nil {
+ logger.Error("Failed to decode token response: %v", err)
return nil, err
}
// Parse character info from token
name, _ := parseTokenCharacter(tr.AccessToken)
+ logger.Info("Successfully exchanged code for token, character: %s", name)
return &Token{
CharacterName: name,
@@ -297,6 +372,7 @@ func (s *SSO) exchangeCodeForToken(ctx context.Context, code, verifier string) (
}
func (s *SSO) refreshToken(ctx context.Context, token *Token) error {
+ logger.Debug("Refreshing token for character %s", token.CharacterName)
form := url.Values{}
form.Set("grant_type", "refresh_token")
form.Set("refresh_token", token.RefreshToken)
@@ -304,23 +380,28 @@ func (s *SSO) refreshToken(ctx context.Context, token *Token) error {
req, err := http.NewRequestWithContext(ctx, http.MethodPost, issuerTokenURL, strings.NewReader(form.Encode()))
if err != nil {
+ logger.Error("Failed to create token refresh request: %v", err)
return err
}
req.Header.Set("Content-Type", "application/x-www-form-urlencoded")
+ logger.Debug("Sending token refresh request to %s", issuerTokenURL)
resp, err := http.DefaultClient.Do(req)
if err != nil {
+ logger.Error("Token refresh request failed: %v", err)
return err
}
defer resp.Body.Close()
if resp.StatusCode < 200 || resp.StatusCode >= 300 {
b, _ := io.ReadAll(resp.Body)
+ logger.Error("Token refresh failed with status %d: %s", resp.StatusCode, string(b))
return fmt.Errorf("token refresh failed: %s: %s", resp.Status, string(b))
}
var tr tokenResponse
if err := json.NewDecoder(resp.Body).Decode(&tr); err != nil {
+ logger.Error("Failed to decode refresh token response: %v", err)
return err
}
@@ -333,7 +414,14 @@ func (s *SSO) refreshToken(ctx context.Context, token *Token) error {
token.ExpiresAt = time.Now().Add(time.Duration(tr.ExpiresIn-30) * time.Second)
}
- return s.db.SaveTokenForCharacter(token)
+ logger.Debug("Saving refreshed token to database for character %s", token.CharacterName)
+ if err := s.db.SaveTokenForCharacter(token); err != nil {
+ logger.Error("Failed to save refreshed token: %v", err)
+ return err
+ }
+
+ logger.Info("Token refreshed successfully for character %s", token.CharacterName)
+ return nil
}
// Utility functions