feat: migrate timestamps to int64 and security improvements

- Convert all time.Time fields to int64 Unix milliseconds (UTC)
- Add PostgreSQL migration to convert timestamp columns to bigint
- Reduce Binance sync window from 7 days to 24 hours
- Fix dashboard trader name visibility (add nofx-text-main color)
- Add position value column to history table
- Remove hardcoded API keys from test files
This commit is contained in:
tinkle-community
2026-01-06 15:56:07 +08:00
parent 5c4c9cdc99
commit 799d8b9c2e
22 changed files with 1620 additions and 231 deletions
+9 -9
View File
@@ -34,7 +34,7 @@ func (t *AsterTrader) SyncOrdersFromAster(traderID string, exchangeID string, ex
// Sort trades by time ASC (oldest first) for proper position building
sort.Slice(trades, func(i, j int) bool {
return trades[i].Time.Before(trades[j].Time)
return trades[i].Time.UnixMilli() < trades[j].Time.UnixMilli()
})
// Process trades one by one (no transaction to avoid deadlock)
@@ -68,8 +68,8 @@ func (t *AsterTrader) SyncOrdersFromAster(traderID string, exchangeID string, ex
// Normalize side for storage
side := strings.ToUpper(trade.Side)
// Create order record - use UTC time to avoid timezone issues
tradeTimeUTC := trade.Time.UTC()
// Create order record - use Unix milliseconds UTC
tradeTimeMs := trade.Time.UTC().UnixMilli()
orderRecord := &store.TraderOrder{
TraderID: traderID,
ExchangeID: exchangeID, // UUID
@@ -86,9 +86,9 @@ func (t *AsterTrader) SyncOrdersFromAster(traderID string, exchangeID string, ex
FilledQuantity: trade.Quantity,
AvgFillPrice: trade.Price,
Commission: trade.Fee,
FilledAt: tradeTimeUTC,
CreatedAt: tradeTimeUTC,
UpdatedAt: tradeTimeUTC,
FilledAt: tradeTimeMs,
CreatedAt: tradeTimeMs,
UpdatedAt: tradeTimeMs,
}
// Insert order record
@@ -97,7 +97,7 @@ func (t *AsterTrader) SyncOrdersFromAster(traderID string, exchangeID string, ex
continue
}
// Create fill record - use UTC time
// Create fill record - use Unix milliseconds UTC
fillRecord := &store.TraderFill{
TraderID: traderID,
ExchangeID: exchangeID, // UUID
@@ -114,7 +114,7 @@ func (t *AsterTrader) SyncOrdersFromAster(traderID string, exchangeID string, ex
CommissionAsset: "USDT",
RealizedPnL: trade.RealizedPnL,
IsMaker: false,
CreatedAt: tradeTimeUTC,
CreatedAt: tradeTimeMs,
}
if err := orderStore.CreateFill(fillRecord); err != nil {
@@ -126,7 +126,7 @@ func (t *AsterTrader) SyncOrdersFromAster(traderID string, exchangeID string, ex
traderID, exchangeID, exchangeType,
symbol, positionSide, orderAction,
trade.Quantity, trade.Price, trade.Fee, trade.RealizedPnL,
trade.Time, trade.TradeID,
tradeTimeMs, trade.TradeID,
); err != nil {
logger.Infof(" ⚠️ Failed to sync position for trade %s: %v", trade.TradeID, err)
} else {
+10 -7
View File
@@ -744,8 +744,8 @@ func (at *AutoTrader) buildTradingContext() (*kernel.Context, error) {
// Priority 1: Get from database (trader_positions table) - most accurate
if at.store != nil {
if dbPos, err := at.store.Position().GetOpenPositionBySymbol(at.id, symbol, side); err == nil && dbPos != nil {
if !dbPos.EntryTime.IsZero() {
updateTime = dbPos.EntryTime.UnixMilli()
if dbPos.EntryTime > 0 {
updateTime = dbPos.EntryTime
}
}
}
@@ -1967,6 +1967,7 @@ func (at *AutoTrader) recordPositionChange(orderID, symbol, side, action string,
switch action {
case "open_long", "open_short":
// Open position: create new position record
nowMs := time.Now().UTC().UnixMilli()
pos := &store.TraderPosition{
TraderID: at.id,
ExchangeID: at.exchangeID, // Exchange account UUID
@@ -1976,9 +1977,11 @@ func (at *AutoTrader) recordPositionChange(orderID, symbol, side, action string,
Quantity: quantity,
EntryPrice: price,
EntryOrderID: orderID,
EntryTime: time.Now().UTC(),
EntryTime: nowMs,
Leverage: leverage,
Status: "OPEN",
CreatedAt: nowMs,
UpdatedAt: nowMs,
}
if err := at.store.Position().Create(pos); err != nil {
logger.Infof(" ⚠️ Failed to record position: %v", err)
@@ -1996,7 +1999,7 @@ func (at *AutoTrader) recordPositionChange(orderID, symbol, side, action string,
at.id, at.exchangeID, at.exchange,
symbol, side, action,
quantity, price, fee, 0, // realizedPnL will be calculated
time.Now().UTC(), orderID,
time.Now().UTC().UnixMilli(), orderID,
); err != nil {
logger.Infof(" ⚠️ Failed to process close position: %v", err)
} else {
@@ -2049,8 +2052,8 @@ func (at *AutoTrader) createOrderRecord(orderID, symbol, action, positionSide st
ReduceOnly: reduceOnly,
ClosePosition: reduceOnly,
OrderAction: orderAction,
CreatedAt: time.Now().UTC(),
UpdatedAt: time.Now().UTC(),
CreatedAt: time.Now().UTC().UnixMilli(),
UpdatedAt: time.Now().UTC().UnixMilli(),
}
}
@@ -2091,7 +2094,7 @@ func (at *AutoTrader) recordOrderFill(orderRecordID int64, exchangeOrderID, symb
CommissionAsset: "USDT",
RealizedPnL: 0, // Will be calculated for close orders
IsMaker: false, // Market orders are usually taker
CreatedAt: time.Now().UTC(),
CreatedAt: time.Now().UTC().UnixMilli(),
}
// Calculate realized PnL for close orders
+27
View File
@@ -1244,3 +1244,30 @@ func (t *FuturesTrader) GetCommissionSymbols(lastSyncTime time.Time) ([]string,
return symbols, nil
}
// GetPnLSymbols returns symbols that have REALIZED_PNL records since lastSyncTime
// This is a fallback when COMMISSION detection fails (VIP users, BNB fee discount)
func (t *FuturesTrader) GetPnLSymbols(lastSyncTime time.Time) ([]string, error) {
incomes, err := t.client.NewGetIncomeHistoryService().
IncomeType("REALIZED_PNL").
StartTime(lastSyncTime.UnixMilli()).
Limit(1000).
Do(context.Background())
if err != nil {
return nil, fmt.Errorf("failed to get PnL history: %w", err)
}
symbolMap := make(map[string]bool)
for _, income := range incomes {
if income.Symbol != "" {
symbolMap[income.Symbol] = true
}
}
var symbols []string
for symbol := range symbolMap {
symbols = append(symbols, symbol)
}
return symbols, nil
}
+100 -26
View File
@@ -11,9 +11,9 @@ import (
"time"
)
// syncState stores the last sync time for incremental sync
// syncState stores the last sync time (Unix ms) for incremental sync
var (
binanceSyncState = make(map[string]time.Time) // exchangeID -> lastSyncTime
binanceSyncState = make(map[string]int64) // exchangeID -> lastSyncTimeMs (Unix ms)
binanceSyncStateMutex sync.RWMutex
)
@@ -25,42 +25,106 @@ func (t *FuturesTrader) SyncOrdersFromBinance(traderID string, exchangeID string
return fmt.Errorf("store is nil")
}
// Get last sync time (default to 24 hours ago for first sync)
orderStore := st.Order()
// Get last sync time (Unix ms) - first try memory, then database, then default
binanceSyncStateMutex.RLock()
lastSyncTime, exists := binanceSyncState[exchangeID]
lastSyncTimeMs, exists := binanceSyncState[exchangeID]
binanceSyncStateMutex.RUnlock()
nowMs := time.Now().UTC().UnixMilli()
if !exists {
lastSyncTime = time.Now().Add(-24 * time.Hour)
// Try to get last fill time from database (persist across restarts)
lastFillTimeMs, err := orderStore.GetLastFillTimeByExchange(exchangeID)
if err == nil && lastFillTimeMs > 0 {
// If recovered time is in the future, it's clearly wrong - use default
if lastFillTimeMs > nowMs {
logger.Infof("⚠️ DB sync time %d is in the future (now: %d), using default",
lastFillTimeMs, nowMs)
lastSyncTimeMs = nowMs - 24*60*60*1000 // 24 hours ago
} else {
// Add 1 second buffer to avoid re-fetching the same fill
lastSyncTimeMs = lastFillTimeMs + 1000
logger.Infof("📅 Recovered last sync time from DB: %s (UTC)",
time.UnixMilli(lastSyncTimeMs).UTC().Format("2006-01-02 15:04:05"))
}
} else {
// First sync: go back 24 hours
lastSyncTimeMs = nowMs - 24*60*60*1000
logger.Infof("📅 First sync, starting from 24 hours ago: %s (UTC)",
time.UnixMilli(lastSyncTimeMs).UTC().Format("2006-01-02 15:04:05"))
}
}
// Record current time BEFORE querying, to avoid missing trades during sync
// This prevents race condition where trades happen between query and lastSyncTime update
syncStartTime := time.Now()
syncStartTimeMs := nowMs
logger.Infof("🔄 Syncing Binance trades from: %s", lastSyncTime.Format(time.RFC3339))
logger.Infof("🔄 Syncing Binance trades from: %s (UTC)",
time.UnixMilli(lastSyncTimeMs).UTC().Format("2006-01-02 15:04:05"))
// Step 1: Get max trade IDs from local DB for incremental sync
orderStore := st.Order()
maxTradeIDs, err := orderStore.GetMaxTradeIDsByExchange(exchangeID)
if err != nil {
logger.Infof(" ⚠️ Failed to get max trade IDs: %v, will use time-based query", err)
maxTradeIDs = make(map[string]int64)
}
// Step 2: Use COMMISSION to detect which symbols have new trades (1 API call)
changedSymbols, err := t.GetCommissionSymbols(lastSyncTime)
// Step 2: Detect symbols to sync using multiple methods
// COMMISSION detection may miss trades (VIP users, BNB discount, 0-fee trades)
symbolMap := make(map[string]bool)
lastSyncTime := time.UnixMilli(lastSyncTimeMs) // Convert to time.Time for API calls
// Method 1: COMMISSION income detection
commissionSymbols, err := t.GetCommissionSymbols(lastSyncTime)
if err != nil {
logger.Infof(" ⚠️ Failed to get commission symbols: %v, falling back to positions", err)
// Fallback: only sync symbols with active positions
changedSymbols = t.getPositionSymbols()
logger.Infof(" ⚠️ Failed to get commission symbols: %v", err)
} else {
logger.Infof(" 📋 COMMISSION symbols found: %d - %v", len(commissionSymbols), commissionSymbols)
for _, s := range commissionSymbols {
symbolMap[s] = true
}
}
// Method 2: Always include active positions (catches trades that COMMISSION missed)
positionSymbols := t.getPositionSymbols()
logger.Infof(" 📋 Position symbols found: %d - %v", len(positionSymbols), positionSymbols)
for _, s := range positionSymbols {
symbolMap[s] = true
}
// Method 3: Include symbols from recent fills in DB (in case some were partially synced)
recentSymbols, _ := orderStore.GetRecentFillSymbolsByExchange(exchangeID, lastSyncTimeMs)
logger.Infof(" 📋 Recent fill symbols found: %d - %v", len(recentSymbols), recentSymbols)
for _, s := range recentSymbols {
symbolMap[s] = true
}
// Method 4: FALLBACK - Query REALIZED_PNL income to find symbols with closed trades
// This catches trades that COMMISSION missed (VIP users, BNB fee discount)
if len(symbolMap) == 0 {
logger.Infof(" 🔍 No symbols found, trying REALIZED_PNL fallback...")
pnlSymbols, err := t.GetPnLSymbols(lastSyncTime)
if err != nil {
logger.Infof(" ⚠️ Failed to get PnL symbols: %v", err)
} else {
logger.Infof(" 📋 REALIZED_PNL symbols found: %d - %v", len(pnlSymbols), pnlSymbols)
for _, s := range pnlSymbols {
symbolMap[s] = true
}
}
}
var changedSymbols []string
for s := range symbolMap {
changedSymbols = append(changedSymbols, s)
}
if len(changedSymbols) == 0 {
logger.Infof("📭 No symbols with new trades to sync")
// Update last sync time even if no changes
binanceSyncStateMutex.Lock()
binanceSyncState[exchangeID] = syncStartTime
binanceSyncState[exchangeID] = syncStartTimeMs
binanceSyncStateMutex.Unlock()
return nil
}
@@ -98,7 +162,7 @@ func (t *FuturesTrader) SyncOrdersFromBinance(traderID string, exchangeID string
// This prevents data loss when some symbols fail due to rate limit or network issues
if len(failedSymbols) == 0 {
binanceSyncStateMutex.Lock()
binanceSyncState[exchangeID] = syncStartTime
binanceSyncState[exchangeID] = syncStartTimeMs
binanceSyncStateMutex.Unlock()
} else {
logger.Infof(" ⚠️ %d symbols failed, not updating lastSyncTime to retry next time: %v", len(failedSymbols), failedSymbols)
@@ -110,7 +174,7 @@ func (t *FuturesTrader) SyncOrdersFromBinance(traderID string, exchangeID string
// Sort trades by time ASC (oldest first) for proper position building
sort.Slice(allTrades, func(i, j int) bool {
return allTrades[i].Time.Before(allTrades[j].Time)
return allTrades[i].Time.UnixMilli() < allTrades[j].Time.UnixMilli()
})
// Process trades one by one
@@ -145,8 +209,8 @@ func (t *FuturesTrader) SyncOrdersFromBinance(traderID string, exchangeID string
// Normalize side
side := strings.ToUpper(trade.Side)
// Create order record - use UTC time to avoid timezone issues
tradeTimeUTC := trade.Time.UTC()
// Create order record - use Unix milliseconds UTC
tradeTimeMs := trade.Time.UTC().UnixMilli()
orderRecord := &store.TraderOrder{
TraderID: traderID,
ExchangeID: exchangeID,
@@ -163,9 +227,9 @@ func (t *FuturesTrader) SyncOrdersFromBinance(traderID string, exchangeID string
FilledQuantity: trade.Quantity,
AvgFillPrice: trade.Price,
Commission: trade.Fee,
FilledAt: tradeTimeUTC,
CreatedAt: tradeTimeUTC,
UpdatedAt: tradeTimeUTC,
FilledAt: tradeTimeMs,
CreatedAt: tradeTimeMs,
UpdatedAt: tradeTimeMs,
}
// Insert order record
@@ -174,7 +238,7 @@ func (t *FuturesTrader) SyncOrdersFromBinance(traderID string, exchangeID string
continue
}
// Create fill record - use UTC time
// Create fill record - use Unix milliseconds UTC
fillRecord := &store.TraderFill{
TraderID: traderID,
ExchangeID: exchangeID,
@@ -191,7 +255,7 @@ func (t *FuturesTrader) SyncOrdersFromBinance(traderID string, exchangeID string
CommissionAsset: "USDT",
RealizedPnL: trade.RealizedPnL,
IsMaker: false,
CreatedAt: tradeTimeUTC,
CreatedAt: tradeTimeMs,
}
if err := orderStore.CreateFill(fillRecord); err != nil {
@@ -203,7 +267,7 @@ func (t *FuturesTrader) SyncOrdersFromBinance(traderID string, exchangeID string
traderID, exchangeID, exchangeType,
symbol, positionSide, orderAction,
trade.Quantity, trade.Price, trade.Fee, trade.RealizedPnL,
trade.Time, trade.TradeID,
tradeTimeMs, trade.TradeID,
); err != nil {
logger.Infof(" ⚠️ Failed to sync position for trade %s: %v", trade.TradeID, err)
} else {
@@ -211,8 +275,9 @@ func (t *FuturesTrader) SyncOrdersFromBinance(traderID string, exchangeID string
}
syncedCount++
logger.Infof(" ✅ Synced trade: %s %s %s qty=%.6f price=%.6f pnl=%.2f fee=%.6f action=%s",
trade.TradeID, symbol, side, trade.Quantity, trade.Price, trade.RealizedPnL, trade.Fee, orderAction)
logger.Infof(" ✅ Synced trade: %s %s %s qty=%.6f price=%.6f pnl=%.2f fee=%.6f action=%s time=%s(UTC)",
trade.TradeID, symbol, side, trade.Quantity, trade.Price, trade.RealizedPnL, trade.Fee, orderAction,
trade.Time.UTC().Format("01-02 15:04:05"))
}
logger.Infof("✅ Binance order sync completed: %d new trades synced", syncedCount)
@@ -279,6 +344,15 @@ func (t *FuturesTrader) determineOrderAction(side, positionSide string, realized
// StartOrderSync starts background order sync task for Binance
func (t *FuturesTrader) StartOrderSync(traderID string, exchangeID string, exchangeType string, st *store.Store, interval time.Duration) {
// Run first sync immediately
go func() {
logger.Infof("🔄 Running initial Binance order sync...")
if err := t.SyncOrdersFromBinance(traderID, exchangeID, exchangeType, st); err != nil {
logger.Infof("⚠️ Initial Binance order sync failed: %v", err)
}
}()
// Then run periodically
ticker := time.NewTicker(interval)
go func() {
for range ticker.C {
+461
View File
@@ -0,0 +1,461 @@
package trader
import (
"context"
"fmt"
"os"
"testing"
"time"
)
func skipIfNoLiveTest(t *testing.T) {
if os.Getenv("BINANCE_LIVE_TEST") != "1" {
t.Skip("Skipping live test. Set BINANCE_LIVE_TEST=1 to run")
}
}
func getBinanceTestCredentials(t *testing.T) (string, string) {
apiKey := os.Getenv("BINANCE_TEST_API_KEY")
secretKey := os.Getenv("BINANCE_TEST_SECRET_KEY")
if apiKey == "" || secretKey == "" {
t.Skip("Skipping test. Set BINANCE_TEST_API_KEY and BINANCE_TEST_SECRET_KEY env vars")
}
return apiKey, secretKey
}
func createBinanceTestTrader(t *testing.T) *FuturesTrader {
apiKey, secretKey := getBinanceTestCredentials(t)
trader := NewFuturesTrader(apiKey, secretKey, "test-user")
return trader
}
// TestBinanceConnection tests basic API connectivity
func TestBinanceConnection(t *testing.T) {
skipIfNoLiveTest(t)
trader := createBinanceTestTrader(t)
balance, err := trader.GetBalance()
if err != nil {
t.Fatalf("Failed to get balance: %v", err)
}
t.Logf("✅ Connection OK - Balance: %v", balance)
}
// TestBinanceGetPositions tests position retrieval
func TestBinanceGetPositions(t *testing.T) {
skipIfNoLiveTest(t)
trader := createBinanceTestTrader(t)
positions, err := trader.GetPositions()
if err != nil {
t.Fatalf("Failed to get positions: %v", err)
}
t.Logf("📊 Found %d positions with non-zero amount:", len(positions))
for i, pos := range positions {
symbol := pos["symbol"].(string)
side := pos["side"].(string)
posAmt := pos["positionAmt"].(float64)
entryPrice := pos["entryPrice"].(float64)
unrealizedPnl := pos["unRealizedProfit"].(float64)
t.Logf(" [%d] %s %s: qty=%.6f entry=%.4f pnl=%.4f",
i+1, symbol, side, posAmt, entryPrice, unrealizedPnl)
}
}
// TestBinanceGetCommissionSymbols tests COMMISSION income detection
func TestBinanceGetCommissionSymbols(t *testing.T) {
skipIfNoLiveTest(t)
trader := createBinanceTestTrader(t)
// Test different time ranges
timeRanges := []struct {
name string
duration time.Duration
}{
{"1 hour", 1 * time.Hour},
{"24 hours", 24 * time.Hour},
{"7 days", 7 * 24 * time.Hour},
{"30 days", 30 * 24 * time.Hour},
}
for _, tr := range timeRanges {
startTime := time.Now().Add(-tr.duration)
symbols, err := trader.GetCommissionSymbols(startTime)
if err != nil {
t.Logf("❌ %s: Failed to get commission symbols: %v", tr.name, err)
continue
}
t.Logf("📋 %s: COMMISSION symbols = %d - %v", tr.name, len(symbols), symbols)
}
}
// TestBinanceGetPnLSymbols tests REALIZED_PNL income detection
func TestBinanceGetPnLSymbols(t *testing.T) {
skipIfNoLiveTest(t)
trader := createBinanceTestTrader(t)
timeRanges := []struct {
name string
duration time.Duration
}{
{"1 hour", 1 * time.Hour},
{"24 hours", 24 * time.Hour},
{"7 days", 7 * 24 * time.Hour},
{"30 days", 30 * 24 * time.Hour},
}
for _, tr := range timeRanges {
startTime := time.Now().Add(-tr.duration)
symbols, err := trader.GetPnLSymbols(startTime)
if err != nil {
t.Logf("❌ %s: Failed to get PnL symbols: %v", tr.name, err)
continue
}
t.Logf("📋 %s: REALIZED_PNL symbols = %d - %v", tr.name, len(symbols), symbols)
}
}
// TestBinanceGetAllIncomeTypes tests all income types to understand data availability
func TestBinanceGetAllIncomeTypes(t *testing.T) {
skipIfNoLiveTest(t)
trader := createBinanceTestTrader(t)
// All possible income types from Binance API
incomeTypes := []string{
"TRANSFER",
"WELCOME_BONUS",
"REALIZED_PNL",
"FUNDING_FEE",
"COMMISSION",
"INSURANCE_CLEAR",
"REFERRAL_KICKBACK",
"COMMISSION_REBATE",
"API_REBATE",
"CONTEST_REWARD",
"CROSS_COLLATERAL_TRANSFER",
"OPTIONS_PREMIUM_FEE",
"OPTIONS_SETTLE_PROFIT",
"INTERNAL_TRANSFER",
"AUTO_EXCHANGE",
"DELIVERED_SETTELMENT",
"COIN_SWAP_DEPOSIT",
"COIN_SWAP_WITHDRAW",
"POSITION_LIMIT_INCREASE_FEE",
}
startTime := time.Now().Add(-7 * 24 * time.Hour)
t.Logf("🔍 Checking all income types from %s:", startTime.Format(time.RFC3339))
for _, incomeType := range incomeTypes {
incomes, err := trader.client.NewGetIncomeHistoryService().
IncomeType(incomeType).
StartTime(startTime.UnixMilli()).
Limit(100).
Do(context.Background())
if err != nil {
t.Logf(" ❌ %s: error - %v", incomeType, err)
continue
}
if len(incomes) > 0 {
symbolMap := make(map[string]int)
for _, inc := range incomes {
if inc.Symbol != "" {
symbolMap[inc.Symbol]++
}
}
t.Logf(" ✅ %s: %d records, symbols: %v", incomeType, len(incomes), symbolMap)
} else {
t.Logf(" ⚪ %s: 0 records", incomeType)
}
}
}
// TestBinanceGetTradesForSymbol tests trade retrieval for specific symbols
func TestBinanceGetTradesForSymbol(t *testing.T) {
skipIfNoLiveTest(t)
trader := createBinanceTestTrader(t)
// Common trading pairs
symbols := []string{"BTCUSDT", "ETHUSDT", "SOLUSDT", "BNBUSDT", "XRPUSDT"}
startTime := time.Now().Add(-7 * 24 * time.Hour)
t.Logf("🔍 Checking trades for common symbols from %s:", startTime.Format(time.RFC3339))
for _, symbol := range symbols {
trades, err := trader.GetTradesForSymbol(symbol, startTime, 100)
if err != nil {
t.Logf(" ❌ %s: error - %v", symbol, err)
continue
}
if len(trades) > 0 {
t.Logf(" ✅ %s: %d trades", symbol, len(trades))
// Print first and last trade
first := trades[0]
last := trades[len(trades)-1]
t.Logf(" First: %s %s %s qty=%.6f price=%.4f pnl=%.4f time=%s",
first.TradeID, first.Symbol, first.Side,
first.Quantity, first.Price, first.RealizedPnL,
first.Time.Format(time.RFC3339))
if len(trades) > 1 {
t.Logf(" Last: %s %s %s qty=%.6f price=%.4f pnl=%.4f time=%s",
last.TradeID, last.Symbol, last.Side,
last.Quantity, last.Price, last.RealizedPnL,
last.Time.Format(time.RFC3339))
}
} else {
t.Logf(" ⚪ %s: 0 trades", symbol)
}
}
}
// TestBinanceTimestampFormats tests different timestamp formats
func TestBinanceTimestampFormats(t *testing.T) {
skipIfNoLiveTest(t)
now := time.Now()
nowUTC := time.Now().UTC()
t.Logf("🕐 Time comparison:")
t.Logf(" time.Now(): %s (UnixMilli: %d)", now.Format(time.RFC3339), now.UnixMilli())
t.Logf(" time.Now().UTC(): %s (UnixMilli: %d)", nowUTC.Format(time.RFC3339), nowUTC.UnixMilli())
t.Logf(" Difference: %v", now.Sub(nowUTC))
// The key insight: UnixMilli() should be the SAME regardless of timezone
if now.UnixMilli() != nowUTC.UnixMilli() {
t.Errorf("❌ UnixMilli() differs between local and UTC! This should never happen.")
} else {
t.Logf(" ✅ UnixMilli() is the same (correct behavior)")
}
// Test what happens when we parse a time stored in DB
// Simulate old DB value stored in local time
oldLocalTime := time.Date(2026, 1, 6, 18, 0, 0, 0, time.Local) // 18:00 local
oldLocalTimeAsUTC := time.Date(2026, 1, 6, 18, 0, 0, 0, time.UTC) // Same numbers but UTC
t.Logf("\n🔍 Timezone mismatch scenario:")
t.Logf(" Old DB time (local): %s (UnixMilli: %d)", oldLocalTime.Format(time.RFC3339), oldLocalTime.UnixMilli())
t.Logf(" Same time parsed as UTC: %s (UnixMilli: %d)", oldLocalTimeAsUTC.Format(time.RFC3339), oldLocalTimeAsUTC.UnixMilli())
t.Logf(" Difference: %v", time.Duration(oldLocalTimeAsUTC.UnixMilli()-oldLocalTime.UnixMilli())*time.Millisecond)
// If server is in +8 timezone, the difference should be 8 hours
_, offset := now.Zone()
t.Logf(" Local timezone offset: %d seconds (%d hours)", offset, offset/3600)
}
// TestBinanceFullSyncSimulation simulates the full sync process
func TestBinanceFullSyncSimulation(t *testing.T) {
skipIfNoLiveTest(t)
trader := createBinanceTestTrader(t)
t.Logf("🔄 Simulating full sync process...")
// Step 1: Determine lastSyncTime (simulating first run)
lastSyncTime := time.Now().UTC().Add(-7 * 24 * time.Hour)
t.Logf("\n📅 Step 1: lastSyncTime = %s", lastSyncTime.Format(time.RFC3339))
// Step 2: Detect symbols using all methods
symbolMap := make(map[string]bool)
// Method 1: COMMISSION
commissionSymbols, err := trader.GetCommissionSymbols(lastSyncTime)
if err != nil {
t.Logf(" ⚠️ COMMISSION failed: %v", err)
} else {
t.Logf(" 📋 COMMISSION symbols: %d - %v", len(commissionSymbols), commissionSymbols)
for _, s := range commissionSymbols {
symbolMap[s] = true
}
}
// Method 2: Positions
positions, err := trader.GetPositions()
if err != nil {
t.Logf(" ⚠️ GetPositions failed: %v", err)
} else {
var posSymbols []string
for _, pos := range positions {
if symbol, ok := pos["symbol"].(string); ok && symbol != "" {
posSymbols = append(posSymbols, symbol)
symbolMap[symbol] = true
}
}
t.Logf(" 📋 Position symbols: %d - %v", len(posSymbols), posSymbols)
}
// Method 3: REALIZED_PNL (fallback)
pnlSymbols, err := trader.GetPnLSymbols(lastSyncTime)
if err != nil {
t.Logf(" ⚠️ REALIZED_PNL failed: %v", err)
} else {
t.Logf(" 📋 REALIZED_PNL symbols: %d - %v", len(pnlSymbols), pnlSymbols)
for _, s := range pnlSymbols {
symbolMap[s] = true
}
}
// Collect all symbols
var allSymbols []string
for s := range symbolMap {
allSymbols = append(allSymbols, s)
}
t.Logf("\n📊 Step 2: Total unique symbols to sync: %d - %v", len(allSymbols), allSymbols)
if len(allSymbols) == 0 {
t.Logf("❌ No symbols found! This is the bug - nothing to sync")
t.Logf("\n🔍 Investigating why no symbols found...")
// Try to query all income (without type filter) to see if there's ANY activity
incomes, err := trader.client.NewGetIncomeHistoryService().
StartTime(lastSyncTime.UnixMilli()).
Limit(100).
Do(context.Background())
if err != nil {
t.Logf(" Failed to get all income: %v", err)
} else {
t.Logf(" All income records (no type filter): %d", len(incomes))
typeCount := make(map[string]int)
for _, inc := range incomes {
typeCount[inc.IncomeType]++
}
t.Logf(" Income types breakdown: %v", typeCount)
}
return
}
// Step 3: Query trades for each symbol
t.Logf("\n📥 Step 3: Querying trades for each symbol...")
totalTrades := 0
for _, symbol := range allSymbols {
trades, err := trader.GetTradesForSymbol(symbol, lastSyncTime, 500)
if err != nil {
t.Logf(" ❌ %s: error - %v", symbol, err)
continue
}
totalTrades += len(trades)
t.Logf(" ✅ %s: %d trades", symbol, len(trades))
// Print sample trades
for i, trade := range trades {
if i >= 3 {
t.Logf(" ... and %d more trades", len(trades)-3)
break
}
t.Logf(" [%d] %s %s %s qty=%.6f price=%.4f pnl=%.4f fee=%.6f time=%s",
i+1, trade.TradeID, trade.Symbol, trade.Side,
trade.Quantity, trade.Price, trade.RealizedPnL, trade.Fee,
trade.Time.Format(time.RFC3339))
}
}
t.Logf("\n✅ Sync simulation complete: %d total trades found across %d symbols",
totalTrades, len(allSymbols))
}
// TestBinanceTradeIDRange tests trade ID ranges to understand the data
func TestBinanceTradeIDRange(t *testing.T) {
skipIfNoLiveTest(t)
trader := createBinanceTestTrader(t)
// First find symbols with trades
startTime := time.Now().Add(-30 * 24 * time.Hour)
commissionSymbols, _ := trader.GetCommissionSymbols(startTime)
pnlSymbols, _ := trader.GetPnLSymbols(startTime)
symbolMap := make(map[string]bool)
for _, s := range commissionSymbols {
symbolMap[s] = true
}
for _, s := range pnlSymbols {
symbolMap[s] = true
}
if len(symbolMap) == 0 {
t.Log("No symbols with activity found")
return
}
t.Logf("🔍 Checking trade ID ranges for symbols with activity:")
for symbol := range symbolMap {
trades, err := trader.GetTradesForSymbol(symbol, startTime, 100)
if err != nil || len(trades) == 0 {
continue
}
var minID, maxID int64 = 1<<62, 0
for _, trade := range trades {
var id int64
fmt.Sscanf(trade.TradeID, "%d", &id)
if id < minID {
minID = id
}
if id > maxID {
maxID = id
}
}
t.Logf(" %s: %d trades, ID range [%d - %d]", symbol, len(trades), minID, maxID)
// Check if any ID exceeds PostgreSQL INTEGER max
if maxID > 2147483647 {
t.Logf(" ⚠️ Max trade ID %d exceeds PostgreSQL INTEGER max (2147483647)", maxID)
}
}
}
// TestBinanceIncomeAPIDirectCall makes direct API call to understand response
func TestBinanceIncomeAPIDirectCall(t *testing.T) {
skipIfNoLiveTest(t)
trader := createBinanceTestTrader(t)
startTime := time.Now().Add(-24 * time.Hour)
t.Logf("🔍 Direct income API call from %s:", startTime.Format(time.RFC3339))
t.Logf(" StartTime UnixMilli: %d", startTime.UnixMilli())
// Call without income type filter to get ALL income
incomes, err := trader.client.NewGetIncomeHistoryService().
StartTime(startTime.UnixMilli()).
Limit(1000).
Do(context.Background())
if err != nil {
t.Fatalf("Failed to get income: %v", err)
}
t.Logf("📋 Total income records: %d", len(incomes))
// Group by type and symbol
typeSymbolCount := make(map[string]map[string]int)
for _, inc := range incomes {
if typeSymbolCount[inc.IncomeType] == nil {
typeSymbolCount[inc.IncomeType] = make(map[string]int)
}
typeSymbolCount[inc.IncomeType][inc.Symbol]++
}
for incType, symbols := range typeSymbolCount {
t.Logf(" %s:", incType)
for symbol, count := range symbols {
if symbol == "" {
symbol = "(no symbol)"
}
t.Logf(" %s: %d records", symbol, count)
}
}
// Print sample records
if len(incomes) > 0 {
t.Logf("\n📝 Sample income records (first 5):")
for i, inc := range incomes {
if i >= 5 {
break
}
t.Logf(" [%d] Type=%s Symbol=%s Amount=%s Time=%s",
i+1, inc.IncomeType, inc.Symbol, inc.Income,
time.UnixMilli(inc.Time).Format(time.RFC3339))
}
}
}
+216
View File
@@ -0,0 +1,216 @@
package trader
import (
"nofx/store"
"os"
"testing"
"time"
)
// TestBinanceSyncE2E tests the complete sync flow end-to-end
func TestBinanceSyncE2E(t *testing.T) {
skipIfNoLiveTest(t)
// Get credentials from environment
apiKey, secretKey := getBinanceTestCredentials(t)
// Create test database using full store initialization (includes table creation)
testDBPath := "/tmp/test_binance_sync.db"
os.Remove(testDBPath) // Clean up previous test
st, err := store.New(testDBPath)
if err != nil {
t.Fatalf("Failed to init test store: %v", err)
}
db := st.GormDB()
// Create trader
trader := NewFuturesTrader(apiKey, secretKey, "test-user")
// Test parameters
traderID := "test-trader-id"
exchangeID := "test-exchange-id"
exchangeType := "binance"
t.Logf("🧪 Running end-to-end sync test...")
t.Logf(" DB Path: %s", testDBPath)
// Run sync
t.Logf("\n📥 Running SyncOrdersFromBinance...")
startTime := time.Now()
err = trader.SyncOrdersFromBinance(traderID, exchangeID, exchangeType, st)
elapsed := time.Since(startTime)
if err != nil {
t.Fatalf("❌ Sync failed: %v", err)
}
t.Logf("✅ Sync completed in %v", elapsed)
// Check results in database
orderStore := st.Order()
// Count orders
var orderCount int64
db.Model(&store.TraderOrder{}).Where("exchange_id = ?", exchangeID).Count(&orderCount)
t.Logf("\n📊 Results:")
t.Logf(" Orders in DB: %d", orderCount)
// Count fills
var fillCount int64
db.Model(&store.TraderFill{}).Where("exchange_id = ?", exchangeID).Count(&fillCount)
t.Logf(" Fills in DB: %d", fillCount)
// Get symbols
var symbols []string
db.Model(&store.TraderFill{}).
Select("DISTINCT symbol").
Where("exchange_id = ?", exchangeID).
Pluck("symbol", &symbols)
t.Logf(" Unique symbols: %d - %v", len(symbols), symbols)
// Check max trade IDs (test the fix)
maxTradeIDs, err := orderStore.GetMaxTradeIDsByExchange(exchangeID)
if err != nil {
t.Logf(" ⚠️ GetMaxTradeIDsByExchange error: %v", err)
} else {
t.Logf(" Max trade IDs per symbol:")
for symbol, maxID := range maxTradeIDs {
if maxID > 2147483647 {
t.Logf(" %s: %d (⚠️ exceeds PostgreSQL INTEGER max)", symbol, maxID)
} else {
t.Logf(" %s: %d", symbol, maxID)
}
}
}
// Sample some orders
var sampleOrders []store.TraderOrder
db.Where("exchange_id = ?", exchangeID).Limit(5).Find(&sampleOrders)
if len(sampleOrders) > 0 {
t.Logf("\n📝 Sample orders:")
for i, order := range sampleOrders {
t.Logf(" [%d] %s %s %s qty=%.6f price=%.4f action=%s time=%s",
i+1, order.ExchangeOrderID, order.Symbol, order.Side,
order.Quantity, order.Price, order.OrderAction,
order.FilledAt.Format(time.RFC3339))
}
}
// Test incremental sync - run again, should find no new trades
t.Logf("\n🔄 Running incremental sync (should skip existing trades)...")
startTime = time.Now()
err = trader.SyncOrdersFromBinance(traderID, exchangeID, exchangeType, st)
elapsed = time.Since(startTime)
if err != nil {
t.Fatalf("❌ Incremental sync failed: %v", err)
}
t.Logf("✅ Incremental sync completed in %v", elapsed)
// Check counts again - should be the same
var newOrderCount int64
db.Model(&store.TraderOrder{}).Where("exchange_id = ?", exchangeID).Count(&newOrderCount)
t.Logf(" Orders after incremental sync: %d (was %d)", newOrderCount, orderCount)
if newOrderCount != orderCount {
t.Logf(" ⚠️ Order count changed - possible duplicate detection issue")
} else {
t.Logf(" ✅ No duplicates - incremental sync working correctly")
}
// Test GetLastFillTimeByExchange
lastFillTime, err := orderStore.GetLastFillTimeByExchange(exchangeID)
if err != nil {
t.Logf(" ⚠️ GetLastFillTimeByExchange error: %v", err)
} else {
t.Logf("\n📅 Last fill time from DB: %s", lastFillTime.Format(time.RFC3339))
// Check if it would be in the future (the bug we fixed)
now := time.Now().UTC()
if lastFillTime.After(now) {
t.Logf(" ❌ BUG: Last fill time is in the future! (now: %s)", now.Format(time.RFC3339))
} else {
t.Logf(" ✅ Last fill time is in the past (correct)")
}
}
// Cleanup
os.Remove(testDBPath)
t.Logf("\n✅ E2E test completed successfully!")
}
// TestBinanceSyncWithExistingData tests sync behavior with pre-existing data
func TestBinanceSyncWithExistingData(t *testing.T) {
skipIfNoLiveTest(t)
// Get credentials from environment
apiKey, secretKey := getBinanceTestCredentials(t)
testDBPath := "/tmp/test_binance_sync_existing.db"
os.Remove(testDBPath)
st, err := store.New(testDBPath)
if err != nil {
t.Fatalf("Failed to init test store: %v", err)
}
db := st.GormDB()
orderStore := st.Order()
trader := NewFuturesTrader(apiKey, secretKey, "test-user")
traderID := "test-trader-id"
exchangeID := "test-exchange-id"
exchangeType := "binance"
// Insert a fake "old" fill with LOCAL time (simulating the bug scenario)
// This tests that our timezone fix works
localTime := time.Now().Add(8 * time.Hour) // Simulate +8 timezone stored as if it were UTC
fakeFill := &store.TraderFill{
TraderID: traderID,
ExchangeID: exchangeID,
ExchangeType: exchangeType,
ExchangeOrderID: "fake-old-order",
ExchangeTradeID: "fake-old-trade",
Symbol: "BTCUSDT",
Side: "BUY",
Price: 50000,
Quantity: 0.001,
QuoteQuantity: 50,
CreatedAt: localTime, // This time is "in the future" if interpreted as UTC
}
if err := orderStore.CreateFill(fakeFill); err != nil {
t.Fatalf("Failed to create fake fill: %v", err)
}
t.Logf("🧪 Testing sync with existing 'future' data...")
t.Logf(" Fake fill time: %s", localTime.Format(time.RFC3339))
t.Logf(" Current UTC time: %s", time.Now().UTC().Format(time.RFC3339))
// Check GetLastFillTimeByExchange
lastFillTime, _ := orderStore.GetLastFillTimeByExchange(exchangeID)
t.Logf(" GetLastFillTimeByExchange returned: %s", lastFillTime.Format(time.RFC3339))
if lastFillTime.After(time.Now().UTC()) {
t.Logf(" ⚠️ Last fill time is in the future - this is the bug scenario!")
}
// Run sync - it should detect the future time and fall back
t.Logf("\n📥 Running sync (should detect future time and fall back)...")
err = trader.SyncOrdersFromBinance(traderID, exchangeID, exchangeType, st)
if err != nil {
t.Fatalf("❌ Sync failed: %v", err)
}
t.Logf("✅ Sync completed")
// Check that trades were actually synced despite the bad data
var fillCount int64
db.Model(&store.TraderFill{}).Where("exchange_id = ?", exchangeID).Count(&fillCount)
t.Logf(" Total fills in DB: %d (includes 1 fake)", fillCount)
if fillCount > 1 {
t.Logf(" ✅ Real trades were synced despite 'future' data!")
} else {
t.Logf(" ❌ No real trades synced - the bug might still exist")
}
os.Remove(testDBPath)
}
+511
View File
@@ -0,0 +1,511 @@
package trader
import (
"context"
"math"
"nofx/store"
"os"
"sort"
"strings"
"testing"
"time"
)
func repeatStr(s string, n int) string {
return strings.Repeat(s, n)
}
// TestBinanceSyncVerification verifies synced data matches exchange data exactly
func TestBinanceSyncVerification(t *testing.T) {
skipIfNoLiveTest(t)
// Get credentials from environment
apiKey, secretKey := getBinanceTestCredentials(t)
// Create test database
testDBPath := "/tmp/test_binance_verify.db"
os.Remove(testDBPath)
st, err := store.New(testDBPath)
if err != nil {
t.Fatalf("Failed to init test store: %v", err)
}
db := st.GormDB()
trader := NewFuturesTrader(apiKey, secretKey, "test-user")
traderID := "test-trader-id"
exchangeID := "test-exchange-id"
exchangeType := "binance"
// Step 1: Run sync
t.Logf("%s", repeatStr("=", 60))
t.Logf("STEP 1: Running order sync...")
t.Logf("%s", repeatStr("=", 60))
err = trader.SyncOrdersFromBinance(traderID, exchangeID, exchangeType, st)
if err != nil {
t.Fatalf("Sync failed: %v", err)
}
// Step 2: Get all trades from exchange for verification
t.Logf("\n%s", repeatStr("=", 60))
t.Logf("STEP 2: Fetching trades from exchange for verification...")
t.Logf("%s", repeatStr("=", 60))
startTime := time.Now().UTC().Add(-7 * 24 * time.Hour)
// Get symbols from DB
var symbols []string
db.Model(&store.TraderFill{}).
Select("DISTINCT symbol").
Where("exchange_id = ?", exchangeID).
Pluck("symbol", &symbols)
t.Logf("Symbols to verify: %v", symbols)
// Fetch all trades from exchange
type ExchangeTrade struct {
TradeID string
Symbol string
Side string
Price float64
Quantity float64
Fee float64
RealizedPnL float64
Time time.Time
}
var exchangeTrades []ExchangeTrade
for _, symbol := range symbols {
trades, err := trader.GetTradesForSymbol(symbol, startTime, 1000)
if err != nil {
t.Logf("⚠️ Failed to get trades for %s: %v", symbol, err)
continue
}
for _, trade := range trades {
exchangeTrades = append(exchangeTrades, ExchangeTrade{
TradeID: trade.TradeID,
Symbol: trade.Symbol,
Side: trade.Side,
Price: trade.Price,
Quantity: trade.Quantity,
Fee: trade.Fee,
RealizedPnL: trade.RealizedPnL,
Time: trade.Time,
})
}
}
t.Logf("Total trades from exchange: %d", len(exchangeTrades))
// Step 3: Get all fills from DB
t.Logf("\n%s", repeatStr("=", 60))
t.Logf("STEP 3: Comparing with local database...")
t.Logf("%s", repeatStr("=", 60))
var dbFills []store.TraderFill
db.Where("exchange_id = ?", exchangeID).Find(&dbFills)
t.Logf("Total fills in DB: %d", len(dbFills))
// Create maps for comparison
exchangeTradeMap := make(map[string]ExchangeTrade)
for _, t := range exchangeTrades {
exchangeTradeMap[t.TradeID] = t
}
dbFillMap := make(map[string]store.TraderFill)
for _, f := range dbFills {
dbFillMap[f.ExchangeTradeID] = f
}
// Step 4: Check for missing trades
t.Logf("\n%s", repeatStr("=", 60))
t.Logf("STEP 4: Checking for MISSING trades (in exchange but not in DB)...")
t.Logf("%s", repeatStr("=", 60))
var missingTrades []ExchangeTrade
for tradeID, trade := range exchangeTradeMap {
if _, exists := dbFillMap[tradeID]; !exists {
missingTrades = append(missingTrades, trade)
}
}
if len(missingTrades) > 0 {
t.Logf("❌ MISSING %d trades:", len(missingTrades))
for i, trade := range missingTrades {
if i >= 10 {
t.Logf(" ... and %d more", len(missingTrades)-10)
break
}
t.Logf(" - %s %s %s qty=%.6f price=%.4f time=%s",
trade.TradeID, trade.Symbol, trade.Side,
trade.Quantity, trade.Price, trade.Time.Format(time.RFC3339))
}
} else {
t.Logf("✅ No missing trades")
}
// Step 5: Check for extra/duplicate trades
t.Logf("\n%s", repeatStr("=", 60))
t.Logf("STEP 5: Checking for EXTRA trades (in DB but not in exchange)...")
t.Logf("%s", repeatStr("=", 60))
var extraTrades []store.TraderFill
for tradeID, fill := range dbFillMap {
if _, exists := exchangeTradeMap[tradeID]; !exists {
extraTrades = append(extraTrades, fill)
}
}
if len(extraTrades) > 0 {
t.Logf("❌ EXTRA %d trades in DB:", len(extraTrades))
for i, fill := range extraTrades {
if i >= 10 {
t.Logf(" ... and %d more", len(extraTrades)-10)
break
}
t.Logf(" - %s %s %s qty=%.6f price=%.4f",
fill.ExchangeTradeID, fill.Symbol, fill.Side,
fill.Quantity, fill.Price)
}
} else {
t.Logf("✅ No extra/duplicate trades")
}
// Step 6: Check for data accuracy
t.Logf("\n%s", repeatStr("=", 60))
t.Logf("STEP 6: Verifying data accuracy (price, qty, fee, pnl)...")
t.Logf("%s", repeatStr("=", 60))
type DataMismatch struct {
TradeID string
Field string
DB float64
Exchange float64
}
var mismatches []DataMismatch
for tradeID, exchangeTrade := range exchangeTradeMap {
dbFill, exists := dbFillMap[tradeID]
if !exists {
continue
}
// Compare price
if !floatEqual(dbFill.Price, exchangeTrade.Price, 0.0001) {
mismatches = append(mismatches, DataMismatch{
TradeID: tradeID, Field: "Price",
DB: dbFill.Price, Exchange: exchangeTrade.Price,
})
}
// Compare quantity
if !floatEqual(dbFill.Quantity, exchangeTrade.Quantity, 0.000001) {
mismatches = append(mismatches, DataMismatch{
TradeID: tradeID, Field: "Quantity",
DB: dbFill.Quantity, Exchange: exchangeTrade.Quantity,
})
}
// Compare fee
if !floatEqual(dbFill.Commission, exchangeTrade.Fee, 0.000001) {
mismatches = append(mismatches, DataMismatch{
TradeID: tradeID, Field: "Fee",
DB: dbFill.Commission, Exchange: exchangeTrade.Fee,
})
}
// Compare realized PnL
if !floatEqual(dbFill.RealizedPnL, exchangeTrade.RealizedPnL, 0.01) {
mismatches = append(mismatches, DataMismatch{
TradeID: tradeID, Field: "RealizedPnL",
DB: dbFill.RealizedPnL, Exchange: exchangeTrade.RealizedPnL,
})
}
}
if len(mismatches) > 0 {
t.Logf("❌ DATA MISMATCHES: %d", len(mismatches))
for i, m := range mismatches {
if i >= 20 {
t.Logf(" ... and %d more", len(mismatches)-20)
break
}
t.Logf(" - %s %s: DB=%.6f, Exchange=%.6f",
m.TradeID, m.Field, m.DB, m.Exchange)
}
} else {
t.Logf("✅ All data matches exactly")
}
// Step 7: Summary by symbol
t.Logf("\n%s", repeatStr("=", 60))
t.Logf("STEP 7: Summary by symbol...")
t.Logf("%s", repeatStr("=", 60))
type SymbolSummary struct {
Symbol string
ExchangeCount int
DBCount int
TotalQty float64
TotalFee float64
TotalPnL float64
ExchangeTotalQty float64
ExchangeTotalFee float64
ExchangeTotalPnL float64
}
summaryMap := make(map[string]*SymbolSummary)
for _, trade := range exchangeTrades {
if summaryMap[trade.Symbol] == nil {
summaryMap[trade.Symbol] = &SymbolSummary{Symbol: trade.Symbol}
}
s := summaryMap[trade.Symbol]
s.ExchangeCount++
s.ExchangeTotalQty += trade.Quantity
s.ExchangeTotalFee += trade.Fee
s.ExchangeTotalPnL += trade.RealizedPnL
}
for _, fill := range dbFills {
if summaryMap[fill.Symbol] == nil {
summaryMap[fill.Symbol] = &SymbolSummary{Symbol: fill.Symbol}
}
s := summaryMap[fill.Symbol]
s.DBCount++
s.TotalQty += fill.Quantity
s.TotalFee += fill.Commission
s.TotalPnL += fill.RealizedPnL
}
t.Logf("\n%-15s %10s %10s %15s %15s %15s", "Symbol", "Exchange", "DB", "Fee(Exc/DB)", "PnL(Exc/DB)", "Match")
t.Logf("%s", repeatStr("-", 80))
for _, s := range summaryMap {
countMatch := s.ExchangeCount == s.DBCount
feeMatch := floatEqual(s.ExchangeTotalFee, s.TotalFee, 0.01)
pnlMatch := floatEqual(s.ExchangeTotalPnL, s.TotalPnL, 0.01)
matchStr := "✅"
if !countMatch || !feeMatch || !pnlMatch {
matchStr = "❌"
}
t.Logf("%-15s %10d %10d %7.2f/%-7.2f %7.2f/%-7.2f %s",
s.Symbol, s.ExchangeCount, s.DBCount,
s.ExchangeTotalFee, s.TotalFee,
s.ExchangeTotalPnL, s.TotalPnL,
matchStr)
}
// Step 8: Position verification
t.Logf("\n%s", repeatStr("=", 60))
t.Logf("STEP 8: Verifying position calculations...")
t.Logf("%s", repeatStr("=", 60))
// Get positions from DB
var dbPositions []store.TraderPosition
db.Where("exchange_id = ? AND status = ?", exchangeID, "closed").Find(&dbPositions)
t.Logf("Closed positions in DB: %d", len(dbPositions))
// Get current positions from exchange
exchangePositions, err := trader.GetPositions()
if err != nil {
t.Logf("⚠️ Failed to get exchange positions: %v", err)
} else {
t.Logf("Active positions on exchange: %d", len(exchangePositions))
for _, pos := range exchangePositions {
t.Logf(" - %s %s qty=%.6f entry=%.4f pnl=%.4f",
pos["symbol"], pos["side"],
pos["positionAmt"], pos["entryPrice"], pos["unRealizedProfit"])
}
}
// Calculate total PnL from trades
var totalRealizedPnL float64
var totalFees float64
for _, fill := range dbFills {
totalRealizedPnL += fill.RealizedPnL
totalFees += fill.Commission
}
t.Logf("\n📊 PnL Summary from DB:")
t.Logf(" Total Realized PnL: %.4f USDT", totalRealizedPnL)
t.Logf(" Total Fees: %.4f USDT", totalFees)
t.Logf(" Net PnL: %.4f USDT", totalRealizedPnL-totalFees)
// Calculate from exchange
var exchangeTotalPnL float64
var exchangeTotalFees float64
for _, trade := range exchangeTrades {
exchangeTotalPnL += trade.RealizedPnL
exchangeTotalFees += trade.Fee
}
t.Logf("\n📊 PnL Summary from Exchange:")
t.Logf(" Total Realized PnL: %.4f USDT", exchangeTotalPnL)
t.Logf(" Total Fees: %.4f USDT", exchangeTotalFees)
t.Logf(" Net PnL: %.4f USDT", exchangeTotalPnL-exchangeTotalFees)
// Compare
pnlMatch := floatEqual(totalRealizedPnL, exchangeTotalPnL, 0.01)
feeMatch := floatEqual(totalFees, exchangeTotalFees, 0.01)
t.Logf("\n%s", repeatStr("=", 60))
t.Logf("FINAL VERIFICATION RESULT")
t.Logf("%s", repeatStr("=", 60))
allPassed := true
if len(missingTrades) > 0 {
t.Logf("❌ Missing trades: %d", len(missingTrades))
allPassed = false
} else {
t.Logf("✅ No missing trades")
}
if len(extraTrades) > 0 {
t.Logf("❌ Extra/duplicate trades: %d", len(extraTrades))
allPassed = false
} else {
t.Logf("✅ No extra/duplicate trades")
}
if len(mismatches) > 0 {
t.Logf("❌ Data mismatches: %d", len(mismatches))
allPassed = false
} else {
t.Logf("✅ All data accurate")
}
if !pnlMatch {
t.Logf("❌ PnL mismatch: DB=%.4f, Exchange=%.4f", totalRealizedPnL, exchangeTotalPnL)
allPassed = false
} else {
t.Logf("✅ PnL matches")
}
if !feeMatch {
t.Logf("❌ Fee mismatch: DB=%.4f, Exchange=%.4f", totalFees, exchangeTotalFees)
allPassed = false
} else {
t.Logf("✅ Fees match")
}
if allPassed {
t.Logf("\n🎉 ALL VERIFICATIONS PASSED!")
} else {
t.Logf("\n⚠️ SOME VERIFICATIONS FAILED - CHECK ABOVE FOR DETAILS")
}
// Cleanup
os.Remove(testDBPath)
}
// floatEqual compares two floats with tolerance
func floatEqual(a, b, tolerance float64) bool {
return math.Abs(a-b) <= tolerance
}
// TestBinanceDetailedTradeComparison shows detailed trade-by-trade comparison
func TestBinanceDetailedTradeComparison(t *testing.T) {
skipIfNoLiveTest(t)
// Get credentials from environment
apiKey, secretKey := getBinanceTestCredentials(t)
trader := NewFuturesTrader(apiKey, secretKey, "test-user")
startTime := time.Now().UTC().Add(-24 * time.Hour)
// Get all income (to find symbols with activity)
incomes, err := trader.client.NewGetIncomeHistoryService().
StartTime(startTime.UnixMilli()).
Limit(100).
Do(context.Background())
if err != nil {
t.Fatalf("Failed to get income: %v", err)
}
// Find unique symbols
symbolMap := make(map[string]bool)
for _, inc := range incomes {
if inc.Symbol != "" {
symbolMap[inc.Symbol] = true
}
}
if len(symbolMap) == 0 {
t.Log("No trading activity in the last 24 hours")
return
}
t.Logf("=%s", repeatStr("=", 100))
t.Logf("DETAILED TRADE REPORT (Last 24 hours)")
t.Logf("=%s", repeatStr("=", 100))
var grandTotalQty float64
var grandTotalFee float64
var grandTotalPnL float64
for symbol := range symbolMap {
trades, err := trader.GetTradesForSymbol(symbol, startTime, 500)
if err != nil {
t.Logf("⚠️ Failed to get trades for %s: %v", symbol, err)
continue
}
if len(trades) == 0 {
continue
}
// Sort by time
sort.Slice(trades, func(i, j int) bool {
return trades[i].Time.Before(trades[j].Time)
})
t.Logf("\n%s", repeatStr("-", 100))
t.Logf("📊 %s - %d trades", symbol, len(trades))
t.Logf("%s", repeatStr("-", 100))
t.Logf("%-15s %-6s %12s %12s %12s %12s %20s",
"TradeID", "Side", "Quantity", "Price", "Fee", "PnL", "Time")
var totalQty, totalFee, totalPnL float64
var buyQty, sellQty float64
for _, trade := range trades {
t.Logf("%-15s %-6s %12.6f %12.4f %12.6f %12.4f %20s",
trade.TradeID, trade.Side,
trade.Quantity, trade.Price, trade.Fee, trade.RealizedPnL,
trade.Time.Format("2006-01-02 15:04:05"))
totalQty += trade.Quantity
totalFee += trade.Fee
totalPnL += trade.RealizedPnL
if trade.Side == "BUY" {
buyQty += trade.Quantity
} else {
sellQty += trade.Quantity
}
}
t.Logf("%s", repeatStr("-", 100))
t.Logf("SUBTOTAL: %d trades, Buy=%.6f, Sell=%.6f, Fee=%.6f, PnL=%.4f",
len(trades), buyQty, sellQty, totalFee, totalPnL)
grandTotalQty += totalQty
grandTotalFee += totalFee
grandTotalPnL += totalPnL
}
t.Logf("\n%s", repeatStr("=", 100))
t.Logf("GRAND TOTAL")
t.Logf("=%s", repeatStr("=", 100))
t.Logf("Total Fee: %.6f USDT", grandTotalFee)
t.Logf("Total PnL: %.4f USDT", grandTotalPnL)
t.Logf("Net PnL: %.4f USDT", grandTotalPnL-grandTotalFee)
}
+9 -9
View File
@@ -146,7 +146,7 @@ func (t *BitgetTrader) SyncOrdersFromBitget(traderID string, exchangeID string,
// Sort trades by time ASC (oldest first) for proper position building
sort.Slice(trades, func(i, j int) bool {
return trades[i].ExecTime.Before(trades[j].ExecTime)
return trades[i].ExecTime.UnixMilli() < trades[j].ExecTime.UnixMilli()
})
// Process trades one by one (no transaction to avoid deadlock)
@@ -174,8 +174,8 @@ func (t *BitgetTrader) SyncOrdersFromBitget(traderID string, exchangeID string,
// Normalize side for storage
side := strings.ToUpper(trade.Side)
// Create order record - use UTC time to avoid timezone issues
execTimeUTC := trade.ExecTime.UTC()
// Create order record - use UTC time in milliseconds to avoid timezone issues
execTimeMs := trade.ExecTime.UTC().UnixMilli()
orderRecord := &store.TraderOrder{
TraderID: traderID,
ExchangeID: exchangeID, // UUID
@@ -192,9 +192,9 @@ func (t *BitgetTrader) SyncOrdersFromBitget(traderID string, exchangeID string,
FilledQuantity: trade.FillQty,
AvgFillPrice: trade.FillPrice,
Commission: trade.Fee,
FilledAt: execTimeUTC,
CreatedAt: execTimeUTC,
UpdatedAt: execTimeUTC,
FilledAt: execTimeMs,
CreatedAt: execTimeMs,
UpdatedAt: execTimeMs,
}
// Insert order record
@@ -203,7 +203,7 @@ func (t *BitgetTrader) SyncOrdersFromBitget(traderID string, exchangeID string,
continue
}
// Create fill record - use UTC time
// Create fill record - use UTC time in milliseconds
fillRecord := &store.TraderFill{
TraderID: traderID,
ExchangeID: exchangeID, // UUID
@@ -220,7 +220,7 @@ func (t *BitgetTrader) SyncOrdersFromBitget(traderID string, exchangeID string,
CommissionAsset: trade.FeeAsset,
RealizedPnL: trade.ProfitLoss,
IsMaker: false,
CreatedAt: execTimeUTC,
CreatedAt: execTimeMs,
}
if err := orderStore.CreateFill(fillRecord); err != nil {
@@ -232,7 +232,7 @@ func (t *BitgetTrader) SyncOrdersFromBitget(traderID string, exchangeID string,
traderID, exchangeID, exchangeType,
symbol, positionSide, trade.OrderAction,
trade.FillQty, trade.FillPrice, trade.Fee, trade.ProfitLoss,
trade.ExecTime, trade.TradeID,
execTimeMs, trade.TradeID,
); err != nil {
logger.Infof(" ⚠️ Failed to sync position for trade %s: %v", trade.TradeID, err)
} else {
+8 -8
View File
@@ -195,7 +195,7 @@ func (t *BybitTrader) SyncOrdersFromBybit(traderID string, exchangeID string, ex
// Sort trades by time ASC (oldest first) for proper position building
sort.Slice(trades, func(i, j int) bool {
return trades[i].ExecTime.Before(trades[j].ExecTime)
return trades[i].ExecTime.UnixMilli() < trades[j].ExecTime.UnixMilli()
})
// Process trades one by one (no transaction to avoid deadlock)
@@ -223,8 +223,8 @@ func (t *BybitTrader) SyncOrdersFromBybit(traderID string, exchangeID string, ex
// Normalize side for storage
side := strings.ToUpper(trade.Side)
// Create order record - use UTC time to avoid timezone issues
execTimeUTC := trade.ExecTime.UTC()
// Create order record - use UTC time in milliseconds to avoid timezone issues
execTimeMs := trade.ExecTime.UTC().UnixMilli()
orderRecord := &store.TraderOrder{
TraderID: traderID,
ExchangeID: exchangeID, // UUID
@@ -241,9 +241,9 @@ func (t *BybitTrader) SyncOrdersFromBybit(traderID string, exchangeID string, ex
FilledQuantity: trade.ExecQty,
AvgFillPrice: trade.ExecPrice,
Commission: trade.ExecFee,
FilledAt: execTimeUTC,
CreatedAt: execTimeUTC,
UpdatedAt: execTimeUTC,
FilledAt: execTimeMs,
CreatedAt: execTimeMs,
UpdatedAt: execTimeMs,
}
// Insert order record
@@ -269,7 +269,7 @@ func (t *BybitTrader) SyncOrdersFromBybit(traderID string, exchangeID string, ex
CommissionAsset: "USDT",
RealizedPnL: trade.ClosedPnL,
IsMaker: trade.IsMaker,
CreatedAt: execTimeUTC,
CreatedAt: execTimeMs,
}
if err := orderStore.CreateFill(fillRecord); err != nil {
@@ -281,7 +281,7 @@ func (t *BybitTrader) SyncOrdersFromBybit(traderID string, exchangeID string, ex
traderID, exchangeID, exchangeType,
symbol, positionSide, trade.OrderAction,
trade.ExecQty, trade.ExecPrice, trade.ExecFee, trade.ClosedPnL,
trade.ExecTime, trade.ExecID,
execTimeMs, trade.ExecID,
); err != nil {
logger.Infof(" ⚠️ Failed to sync position for trade %s: %v", trade.ExecID, err)
} else {
+9 -9
View File
@@ -34,7 +34,7 @@ func (t *HyperliquidTrader) SyncOrdersFromHyperliquid(traderID string, exchangeI
// Sort trades by time ASC (oldest first) for proper position building
sort.Slice(trades, func(i, j int) bool {
return trades[i].Time.Before(trades[j].Time)
return trades[i].Time.UnixMilli() < trades[j].Time.UnixMilli()
})
// Process trades one by one (no transaction to avoid deadlock)
@@ -61,8 +61,8 @@ func (t *HyperliquidTrader) SyncOrdersFromHyperliquid(traderID string, exchangeI
positionSide = "SHORT"
}
// Create order record - use UTC time to avoid timezone issues
tradeTimeUTC := trade.Time.UTC()
// Create order record - use Unix milliseconds UTC
tradeTimeMs := trade.Time.UTC().UnixMilli()
orderRecord := &store.TraderOrder{
TraderID: traderID,
ExchangeID: exchangeID, // UUID
@@ -79,9 +79,9 @@ func (t *HyperliquidTrader) SyncOrdersFromHyperliquid(traderID string, exchangeI
FilledQuantity: trade.Quantity,
AvgFillPrice: trade.Price,
Commission: trade.Fee,
FilledAt: tradeTimeUTC,
CreatedAt: tradeTimeUTC,
UpdatedAt: tradeTimeUTC,
FilledAt: tradeTimeMs,
CreatedAt: tradeTimeMs,
UpdatedAt: tradeTimeMs,
}
// Insert order record
@@ -90,7 +90,7 @@ func (t *HyperliquidTrader) SyncOrdersFromHyperliquid(traderID string, exchangeI
continue
}
// Create fill record - use UTC time
// Create fill record - use Unix milliseconds UTC
fillRecord := &store.TraderFill{
TraderID: traderID,
ExchangeID: exchangeID, // UUID
@@ -107,7 +107,7 @@ func (t *HyperliquidTrader) SyncOrdersFromHyperliquid(traderID string, exchangeI
CommissionAsset: "USDT",
RealizedPnL: trade.RealizedPnL,
IsMaker: false, // Hyperliquid GetTrades doesn't provide maker/taker info
CreatedAt: tradeTimeUTC,
CreatedAt: tradeTimeMs,
}
if err := orderStore.CreateFill(fillRecord); err != nil {
@@ -119,7 +119,7 @@ func (t *HyperliquidTrader) SyncOrdersFromHyperliquid(traderID string, exchangeI
traderID, exchangeID, exchangeType,
symbol, positionSide, orderAction,
trade.Quantity, trade.Price, trade.Fee, trade.RealizedPnL,
trade.Time, trade.TradeID,
tradeTimeMs, trade.TradeID,
); err != nil {
logger.Infof(" ⚠️ Failed to sync position for trade %s: %v", trade.TradeID, err)
} else {
+9 -9
View File
@@ -34,7 +34,7 @@ func (t *LighterTraderV2) SyncOrdersFromLighter(traderID string, exchangeID stri
// Sort trades by time ASC (oldest first) for proper position building
sort.Slice(trades, func(i, j int) bool {
return trades[i].Time.Before(trades[j].Time)
return trades[i].Time.UnixMilli() < trades[j].Time.UnixMilli()
})
// Process trades one by one (no transaction to avoid deadlock)
@@ -70,8 +70,8 @@ func (t *LighterTraderV2) SyncOrdersFromLighter(traderID string, exchangeID stri
}
}
// Create order record - use UTC time to avoid timezone issues
tradeTimeUTC := trade.Time.UTC()
// Create order record - use Unix milliseconds UTC
tradeTimeMs := trade.Time.UTC().UnixMilli()
orderRecord := &store.TraderOrder{
TraderID: traderID,
ExchangeID: exchangeID, // UUID
@@ -88,9 +88,9 @@ func (t *LighterTraderV2) SyncOrdersFromLighter(traderID string, exchangeID stri
FilledQuantity: trade.Quantity,
AvgFillPrice: trade.Price,
Commission: trade.Fee,
FilledAt: tradeTimeUTC,
CreatedAt: tradeTimeUTC,
UpdatedAt: tradeTimeUTC,
FilledAt: tradeTimeMs,
CreatedAt: tradeTimeMs,
UpdatedAt: tradeTimeMs,
}
// Insert order record
@@ -99,7 +99,7 @@ func (t *LighterTraderV2) SyncOrdersFromLighter(traderID string, exchangeID stri
continue
}
// Create fill record - use UTC time
// Create fill record - use Unix milliseconds UTC
fillRecord := &store.TraderFill{
TraderID: traderID,
ExchangeID: exchangeID, // UUID
@@ -116,7 +116,7 @@ func (t *LighterTraderV2) SyncOrdersFromLighter(traderID string, exchangeID stri
CommissionAsset: "USDT",
RealizedPnL: trade.RealizedPnL,
IsMaker: false,
CreatedAt: tradeTimeUTC,
CreatedAt: tradeTimeMs,
}
if err := orderStore.CreateFill(fillRecord); err != nil {
@@ -128,7 +128,7 @@ func (t *LighterTraderV2) SyncOrdersFromLighter(traderID string, exchangeID stri
traderID, exchangeID, exchangeType,
symbol, positionSide, orderAction,
trade.Quantity, trade.Price, trade.Fee, trade.RealizedPnL,
trade.Time, trade.TradeID,
tradeTimeMs, trade.TradeID,
); err != nil {
logger.Infof(" ⚠️ Failed to sync position for trade %s: %v", trade.TradeID, err)
} else {
+9 -9
View File
@@ -169,7 +169,7 @@ func (t *OKXTrader) SyncOrdersFromOKX(traderID string, exchangeID string, exchan
// Sort trades by time ASC (oldest first) for proper position building
sort.Slice(trades, func(i, j int) bool {
return trades[i].ExecTime.Before(trades[j].ExecTime)
return trades[i].ExecTime.UnixMilli() < trades[j].ExecTime.UnixMilli()
})
// Process trades one by one (no transaction to avoid deadlock)
@@ -197,8 +197,8 @@ func (t *OKXTrader) SyncOrdersFromOKX(traderID string, exchangeID string, exchan
// Normalize side for storage
side := strings.ToUpper(trade.Side)
// Create order record - use UTC time to avoid timezone issues
execTimeUTC := trade.ExecTime.UTC()
// Create order record - use UTC time in milliseconds to avoid timezone issues
execTimeMs := trade.ExecTime.UTC().UnixMilli()
orderRecord := &store.TraderOrder{
TraderID: traderID,
ExchangeID: exchangeID, // UUID
@@ -215,9 +215,9 @@ func (t *OKXTrader) SyncOrdersFromOKX(traderID string, exchangeID string, exchan
FilledQuantity: trade.FillQtyBase,
AvgFillPrice: trade.FillPrice,
Commission: trade.Fee,
FilledAt: execTimeUTC,
CreatedAt: execTimeUTC,
UpdatedAt: execTimeUTC,
FilledAt: execTimeMs,
CreatedAt: execTimeMs,
UpdatedAt: execTimeMs,
}
// Insert order record
@@ -226,7 +226,7 @@ func (t *OKXTrader) SyncOrdersFromOKX(traderID string, exchangeID string, exchan
continue
}
// Create fill record - use UTC time
// Create fill record - use UTC time in milliseconds
fillRecord := &store.TraderFill{
TraderID: traderID,
ExchangeID: exchangeID, // UUID
@@ -243,7 +243,7 @@ func (t *OKXTrader) SyncOrdersFromOKX(traderID string, exchangeID string, exchan
CommissionAsset: trade.FeeAsset,
RealizedPnL: 0, // OKX fills don't include PnL per trade
IsMaker: trade.IsMaker,
CreatedAt: execTimeUTC,
CreatedAt: execTimeMs,
}
if err := orderStore.CreateFill(fillRecord); err != nil {
@@ -255,7 +255,7 @@ func (t *OKXTrader) SyncOrdersFromOKX(traderID string, exchangeID string, exchan
traderID, exchangeID, exchangeType,
symbol, positionSide, trade.OrderAction,
trade.FillQtyBase, trade.FillPrice, trade.Fee, 0, // No per-trade PnL from OKX
trade.ExecTime, trade.TradeID,
execTimeMs, trade.TradeID,
); err != nil {
logger.Infof(" ⚠️ Failed to sync position for trade %s: %v", trade.TradeID, err)
} else {
+5 -5
View File
@@ -40,7 +40,7 @@ func CreatePositionSnapshot(traderID, exchangeID, exchangeType string, trader Tr
logger.Infof("📥 Found %d positions on exchange", len(positions))
// Step 3: Create snapshot record for each position
now := time.Now()
nowMs := time.Now().UnixMilli()
createdCount := 0
for _, posMap := range positions {
@@ -74,18 +74,18 @@ func CreatePositionSnapshot(traderID, exchangeID, exchangeType string, trader Tr
TraderID: traderID,
ExchangeID: exchangeID,
ExchangeType: exchangeType,
ExchangePositionID: fmt.Sprintf("snapshot_%s_%s_%d", symbol, side, now.UnixMilli()),
ExchangePositionID: fmt.Sprintf("snapshot_%s_%s_%d", symbol, side, nowMs),
Symbol: symbol,
Side: side,
Quantity: positionAmt,
EntryPrice: entryPrice,
EntryOrderID: "snapshot", // Mark as snapshot
EntryTime: now,
EntryTime: nowMs,
Leverage: int(leverage),
Status: "OPEN",
Source: "snapshot", // Mark source as snapshot
CreatedAt: now,
UpdatedAt: now,
CreatedAt: nowMs,
UpdatedAt: nowMs,
}
if err := positionStore.CreateOpenPosition(snapshotPosition); err != nil {