Fix qualified column reference (like APIL.rid_hub) in a preload:

pkg/common/adapters/database/alias_test.go

@@ -0,0 +1,67 @@
+package database
+
+import (
+	"testing"
+)
+
+func TestNormalizeTableAlias(t *testing.T) {
+	tests := []struct {
+		name          string
+		query         string
+		expectedAlias string
+		tableName     string
+		want          string
+	}{
+		{
+			name:          "strips incorrect alias from simple condition",
+			query:         "APIL.rid_hub = 2576",
+			expectedAlias: "apiproviderlink",
+			tableName:     "apiproviderlink",
+			want:          "rid_hub = 2576",
+		},
+		{
+			name:          "keeps correct alias",
+			query:         "apiproviderlink.rid_hub = 2576",
+			expectedAlias: "apiproviderlink",
+			tableName:     "apiproviderlink",
+			want:          "apiproviderlink.rid_hub = 2576",
+		},
+		{
+			name:          "strips incorrect alias with multiple conditions",
+			query:         "APIL.rid_hub = ? AND APIL.active = ?",
+			expectedAlias: "apiproviderlink",
+			tableName:     "apiproviderlink",
+			want:          "rid_hub = ? AND active = ?",
+		},
+		{
+			name:          "handles mixed correct and incorrect aliases",
+			query:         "APIL.rid_hub = ? AND apiproviderlink.active = ?",
+			expectedAlias: "apiproviderlink",
+			tableName:     "apiproviderlink",
+			want:          "rid_hub = ? AND apiproviderlink.active = ?",
+		},
+		{
+			name:          "handles parentheses",
+			query:         "(APIL.rid_hub = ?)",
+			expectedAlias: "apiproviderlink",
+			tableName:     "apiproviderlink",
+			want:          "(rid_hub = ?)",
+		},
+		{
+			name:          "no alias in query",
+			query:         "rid_hub = ?",
+			expectedAlias: "apiproviderlink",
+			tableName:     "apiproviderlink",
+			want:          "rid_hub = ?",
+		},
+	}
+
+	for _, tt := range tests {
+		t.Run(tt.name, func(t *testing.T) {
+			got := normalizeTableAlias(tt.query, tt.expectedAlias, tt.tableName)
+			if got != tt.want {
+				t.Errorf("normalizeTableAlias() = %q, want %q", got, tt.want)
+			}
+		})
+	}
+}

pkg/common/adapters/database/bun.go

@@ -6,6 +6,7 @@ import (
 	"fmt"
 	"reflect"
 	"strings"
+	"time"
 
 	"github.com/uptrace/bun"
 
@@ -15,6 +16,24 @@ import (
 	"github.com/bitechdev/ResolveSpec/pkg/reflection"
 )
 
+// QueryDebugHook is a Bun query hook that logs all SQL queries including preloads
+type QueryDebugHook struct{}
+
+func (h *QueryDebugHook) BeforeQuery(ctx context.Context, event *bun.QueryEvent) context.Context {
+	return ctx
+}
+
+func (h *QueryDebugHook) AfterQuery(ctx context.Context, event *bun.QueryEvent) {
+	query := event.Query
+	duration := time.Since(event.StartTime)
+
+	if event.Err != nil {
+		logger.Error("SQL Query Failed [%s]: %s. Error: %v", duration, query, event.Err)
+	} else {
+		logger.Debug("SQL Query Success [%s]: %s", duration, query)
+	}
+}
+
 // BunAdapter adapts Bun to work with our Database interface
 // This demonstrates how the abstraction works with different ORMs
 type BunAdapter struct {
@@ -26,6 +45,20 @@ func NewBunAdapter(db *bun.DB) *BunAdapter {
 	return &BunAdapter{db: db}
 }
 
+// EnableQueryDebug enables query debugging which logs all SQL queries including preloads
+// This is useful for debugging preload queries that may be failing
+func (b *BunAdapter) EnableQueryDebug() {
+	b.db.AddQueryHook(&QueryDebugHook{})
+	logger.Info("Bun query debug mode enabled - all SQL queries will be logged")
+}
+
+// DisableQueryDebug removes all query hooks
+func (b *BunAdapter) DisableQueryDebug() {
+	// Create a new DB without hooks
+	// Note: Bun doesn't have a RemoveQueryHook, so we'd need to track hooks manually
+	logger.Info("To disable query debug, recreate the BunAdapter without adding the hook")
+}
+
 func (b *BunAdapter) NewSelect() common.SelectQuery {
 	return &BunSelectQuery{
 		query: b.db.NewSelect(),
@@ -156,10 +189,56 @@ func (b *BunSelectQuery) ColumnExpr(query string, args ...interface{}) common.Se
 }
 
 func (b *BunSelectQuery) Where(query string, args ...interface{}) common.SelectQuery {
+	// If we have a table alias defined, check if the query references a different alias
+	// This can happen in preloads where the user expects a certain alias but Bun generates another
+	if b.tableAlias != "" && b.tableName != "" {
+		// Detect if query contains a qualified column reference (e.g., "APIL.column")
+		// and replace it with the unqualified version or the correct alias
+		query = normalizeTableAlias(query, b.tableAlias, b.tableName)
+	}
 	b.query = b.query.Where(query, args...)
 	return b
 }
 
+// normalizeTableAlias replaces table alias prefixes in SQL conditions
+// This handles cases where a user references a table alias that doesn't match
+// what Bun generates (common in preload contexts)
+func normalizeTableAlias(query, expectedAlias, tableName string) string {
+	// Pattern: <word>.<column> where <word> might be an incorrect alias
+	// We'll look for patterns like "APIL.column" and either:
+	// 1. Remove the alias prefix entirely (safest)
+	// 2. Replace with the expected alias
+
+	// For now, we'll use a simple approach: if the query contains a dot (qualified reference)
+	// and that prefix is not the expected alias or table name, strip it
+
+	// Split on spaces and parentheses to find qualified references
+	parts := strings.FieldsFunc(query, func(r rune) bool {
+		return r == ' ' || r == '(' || r == ')' || r == ','
+	})
+
+	modified := query
+	for _, part := range parts {
+		// Check if this looks like a qualified column reference
+		if dotIndex := strings.Index(part, "."); dotIndex > 0 {
+			prefix := part[:dotIndex]
+			column := part[dotIndex+1:]
+
+			// Check if the prefix matches our expected alias or table name (case-insensitive)
+			if !strings.EqualFold(prefix, expectedAlias) &&
+			   !strings.EqualFold(prefix, tableName) &&
+			   !strings.EqualFold(prefix, strings.ToLower(tableName)) {
+				// This is a different alias - remove the prefix
+				logger.Debug("Stripping incorrect alias '%s' from WHERE condition, keeping just '%s'", prefix, column)
+				// Replace the qualified reference with just the column name
+				modified = strings.ReplaceAll(modified, part, column)
+			}
+		}
+	}
+
+	return modified
+}
+
 func (b *BunSelectQuery) WhereOr(query string, args ...interface{}) common.SelectQuery {
 	b.query = b.query.WhereOr(query, args...)
 	return b
@@ -350,6 +429,28 @@ func (b *BunSelectQuery) PreloadRelation(relation string, apply ...func(common.S
 			db:    b.db,
 		}
 
+		// Try to extract table name and alias from the preload model
+		if model := sq.GetModel(); model != nil && model.Value() != nil {
+			modelValue := model.Value()
+
+			// Extract table name if model implements TableNameProvider
+			if provider, ok := modelValue.(common.TableNameProvider); ok {
+				fullTableName := provider.TableName()
+				wrapper.schema, wrapper.tableName = parseTableName(fullTableName)
+			}
+
+			// Extract table alias if model implements TableAliasProvider
+			if provider, ok := modelValue.(common.TableAliasProvider); ok {
+				wrapper.tableAlias = provider.TableAlias()
+				// Apply the alias to the Bun query so conditions can reference it
+				if wrapper.tableAlias != "" {
+					// Note: Bun's Relation() already sets up the table, but we can add
+					// the alias explicitly if needed
+					logger.Debug("Preload relation '%s' using table alias: %s", relation, wrapper.tableAlias)
+				}
+			}
+		}
+
 		// Start with the interface value (not pointer)
 		current := common.SelectQuery(wrapper)
 
@@ -410,6 +511,9 @@ func (b *BunSelectQuery) Scan(ctx context.Context, dest interface{}) (err error)
 	// Execute the main query first
 	err = b.query.Scan(ctx, dest)
 	if err != nil {
+		// Log SQL string for debugging
+		sqlStr := b.query.String()
+		logger.Error("BunSelectQuery.Scan failed. SQL: %s. Error: %v", sqlStr, err)
 		return err
 	}
 
@@ -438,6 +542,9 @@ func (b *BunSelectQuery) ScanModel(ctx context.Context) (err error) {
 	// Execute the main query first
 	err = b.query.Scan(ctx)
 	if err != nil {
+		// Log SQL string for debugging
+		sqlStr := b.query.String()
+		logger.Error("BunSelectQuery.ScanModel failed. SQL: %s. Error: %v", sqlStr, err)
 		return err
 	}
 
@@ -573,15 +680,25 @@ func (b *BunSelectQuery) Count(ctx context.Context) (count int, err error) {
 	// If Model() was set, use bun's native Count() which works properly
 	if b.hasModel {
 		count, err := b.query.Count(ctx)
+		if err != nil {
+			// Log SQL string for debugging
+			sqlStr := b.query.String()
+			logger.Error("BunSelectQuery.Count failed. SQL: %s. Error: %v", sqlStr, err)
+		}
 		return count, err
 	}
 
 	// Otherwise, wrap as subquery to avoid "Model(nil)" error
 	// This is needed when only Table() is set without a model
-	err = b.db.NewSelect().
+	countQuery := b.db.NewSelect().
 		TableExpr("(?) AS subquery", b.query).
-		ColumnExpr("COUNT(*)").
-		Scan(ctx, &count)
+		ColumnExpr("COUNT(*)")
+	err = countQuery.Scan(ctx, &count)
+	if err != nil {
+		// Log SQL string for debugging
+		sqlStr := countQuery.String()
+		logger.Error("BunSelectQuery.Count (subquery) failed. SQL: %s. Error: %v", sqlStr, err)
+	}
 	return count, err
 }
 
@@ -592,7 +709,13 @@ func (b *BunSelectQuery) Exists(ctx context.Context) (exists bool, err error) {
 			exists = false
 		}
 	}()
-	return b.query.Exists(ctx)
+	exists, err = b.query.Exists(ctx)
+	if err != nil {
+		// Log SQL string for debugging
+		sqlStr := b.query.String()
+		logger.Error("BunSelectQuery.Exists failed. SQL: %s. Error: %v", sqlStr, err)
+	}
+	return exists, err
 }
 
 // BunInsertQuery implements InsertQuery for Bun
@@ -729,6 +852,11 @@ func (b *BunUpdateQuery) Exec(ctx context.Context) (res common.Result, err error
 		}
 	}()
 	result, err := b.query.Exec(ctx)
+	if err != nil {
+		// Log SQL string for debugging
+		sqlStr := b.query.String()
+		logger.Error("BunUpdateQuery.Exec failed. SQL: %s. Error: %v", sqlStr, err)
+	}
 	return &BunResult{result: result}, err
 }
 
@@ -759,6 +887,11 @@ func (b *BunDeleteQuery) Exec(ctx context.Context) (res common.Result, err error
 		}
 	}()
 	result, err := b.query.Exec(ctx)
+	if err != nil {
+		// Log SQL string for debugging
+		sqlStr := b.query.String()
+		logger.Error("BunDeleteQuery.Exec failed. SQL: %s. Error: %v", sqlStr, err)
+	}
 	return &BunResult{result: result}, err
 }
 

pkg/common/adapters/database/gorm.go

@@ -23,6 +23,22 @@ func NewGormAdapter(db *gorm.DB) *GormAdapter {
 	return &GormAdapter{db: db}
 }
 
+// EnableQueryDebug enables query debugging which logs all SQL queries including preloads
+// This is useful for debugging preload queries that may be failing
+func (g *GormAdapter) EnableQueryDebug() *GormAdapter {
+	g.db = g.db.Debug()
+	logger.Info("GORM query debug mode enabled - all SQL queries will be logged")
+	return g
+}
+
+// DisableQueryDebug disables query debugging
+func (g *GormAdapter) DisableQueryDebug() *GormAdapter {
+	// GORM's Debug() creates a new session, so we need to get the base DB
+	// This is a simplified implementation
+	logger.Info("GORM debug mode - create a new adapter without Debug() to disable")
+	return g
+}
+
 func (g *GormAdapter) NewSelect() common.SelectQuery {
 	return &GormSelectQuery{db: g.db}
 }
@@ -282,7 +298,15 @@ func (g *GormSelectQuery) Scan(ctx context.Context, dest interface{}) (err error
 			err = logger.HandlePanic("GormSelectQuery.Scan", r)
 		}
 	}()
-	return g.db.WithContext(ctx).Find(dest).Error
+	err = g.db.WithContext(ctx).Find(dest).Error
+	if err != nil {
+		// Log SQL string for debugging
+		sqlStr := g.db.ToSQL(func(tx *gorm.DB) *gorm.DB {
+			return tx.Find(dest)
+		})
+		logger.Error("GormSelectQuery.Scan failed. SQL: %s. Error: %v", sqlStr, err)
+	}
+	return err
 }
 
 func (g *GormSelectQuery) ScanModel(ctx context.Context) (err error) {
@@ -294,7 +318,15 @@ func (g *GormSelectQuery) ScanModel(ctx context.Context) (err error) {
 	if g.db.Statement.Model == nil {
 		return fmt.Errorf("ScanModel requires Model() to be set before scanning")
 	}
-	return g.db.WithContext(ctx).Find(g.db.Statement.Model).Error
+	err = g.db.WithContext(ctx).Find(g.db.Statement.Model).Error
+	if err != nil {
+		// Log SQL string for debugging
+		sqlStr := g.db.ToSQL(func(tx *gorm.DB) *gorm.DB {
+			return tx.Find(g.db.Statement.Model)
+		})
+		logger.Error("GormSelectQuery.ScanModel failed. SQL: %s. Error: %v", sqlStr, err)
+	}
+	return err
 }
 
 func (g *GormSelectQuery) Count(ctx context.Context) (count int, err error) {
@@ -306,6 +338,13 @@ func (g *GormSelectQuery) Count(ctx context.Context) (count int, err error) {
 	}()
 	var count64 int64
 	err = g.db.WithContext(ctx).Count(&count64).Error
+	if err != nil {
+		// Log SQL string for debugging
+		sqlStr := g.db.ToSQL(func(tx *gorm.DB) *gorm.DB {
+			return tx.Count(&count64)
+		})
+		logger.Error("GormSelectQuery.Count failed. SQL: %s. Error: %v", sqlStr, err)
+	}
 	return int(count64), err
 }
 
@@ -318,6 +357,13 @@ func (g *GormSelectQuery) Exists(ctx context.Context) (exists bool, err error) {
 	}()
 	var count int64
 	err = g.db.WithContext(ctx).Limit(1).Count(&count).Error
+	if err != nil {
+		// Log SQL string for debugging
+		sqlStr := g.db.ToSQL(func(tx *gorm.DB) *gorm.DB {
+			return tx.Limit(1).Count(&count)
+		})
+		logger.Error("GormSelectQuery.Exists failed. SQL: %s. Error: %v", sqlStr, err)
+	}
 	return count > 0, err
 }
 
@@ -456,6 +502,13 @@ func (g *GormUpdateQuery) Exec(ctx context.Context) (res common.Result, err erro
 		}
 	}()
 	result := g.db.WithContext(ctx).Updates(g.updates)
+	if result.Error != nil {
+		// Log SQL string for debugging
+		sqlStr := g.db.ToSQL(func(tx *gorm.DB) *gorm.DB {
+			return tx.Updates(g.updates)
+		})
+		logger.Error("GormUpdateQuery.Exec failed. SQL: %s. Error: %v", sqlStr, result.Error)
+	}
 	return &GormResult{result: result}, result.Error
 }
 
@@ -488,6 +541,13 @@ func (g *GormDeleteQuery) Exec(ctx context.Context) (res common.Result, err erro
 		}
 	}()
 	result := g.db.WithContext(ctx).Delete(g.model)
+	if result.Error != nil {
+		// Log SQL string for debugging
+		sqlStr := g.db.ToSQL(func(tx *gorm.DB) *gorm.DB {
+			return tx.Delete(g.model)
+		})
+		logger.Error("GormDeleteQuery.Exec failed. SQL: %s. Error: %v", sqlStr, result.Error)
+	}
 	return &GormResult{result: result}, result.Error
 }