diff --git a/src/models/player.js b/src/models/player.js index 733c138..8b168ee 100644 --- a/src/models/player.js +++ b/src/models/player.js @@ -1,5 +1,6 @@ const { db } = require('../db'); const { parseDate } = require('../services/rating-calculator'); +const logger = require('../logger'); function getPlayerFromDB(pdgaNumber) { return new Promise((resolve, reject) => { @@ -16,6 +17,7 @@ function getPlayerFromDB(pdgaNumber) { function savePlayerToDB(playerData) { return new Promise((resolve, reject) => { + logger.info({ pdgaNumber: playerData.pdgaNumber, name: playerData.name, currentRating: playerData.rating, ratingChange: playerData.ratingChange, resetColumns: ['predicted_rating', 'std_dev', 'excluded_rounds_count', 'cutoff_rating', 'last_round_update'] }, 'INSERT OR REPLACE on players — derived columns will be reset to NULL'); db.run( `INSERT OR REPLACE INTO players (pdga_number, name, current_rating, rating_change, last_updated) VALUES (?, ?, ?, ?, datetime('now'))`, @@ -172,16 +174,28 @@ function saveRoundHistoryToDB(pdgaNumber, roundData, isIncremental = false) { }); } -function savePredictedRatingToDB(pdgaNumber, predictedRating, stdDev = null, excludedRoundsCount = null, cutoffRating = null) { +function savePredictedRatingToDB(pdgaNumber, predictedRating, stdDev = null, excludedRoundsCount = null, cutoffRating = null, callsite = 'unknown') { return new Promise((resolve, reject) => { - db.run( - 'UPDATE players SET predicted_rating = ?, std_dev = ?, excluded_rounds_count = ?, cutoff_rating = ? WHERE pdga_number = ?', - [predictedRating, stdDev, excludedRoundsCount, cutoffRating, pdgaNumber], - function(err) { - if (err) reject(err); - else resolve(); - } - ); + db.get('SELECT predicted_rating AS oldValue FROM players WHERE pdga_number = ?', [pdgaNumber], (selectErr, row) => { + if (selectErr) return reject(selectErr); + const oldValue = row ? row.oldValue : null; + + db.run( + 'UPDATE players SET predicted_rating = ?, std_dev = ?, excluded_rounds_count = ?, cutoff_rating = ? WHERE pdga_number = ?', + [predictedRating, stdDev, excludedRoundsCount, cutoffRating, pdgaNumber], + function(err) { + if (err) return reject(err); + + const logData = { pdgaNumber, oldValue, newValue: predictedRating, callsite }; + if (predictedRating === 0 && oldValue != null && oldValue > 0) { + logger.warn(logData, 'predicted rating overwritten with 0'); + } else { + logger.info(logData, 'predicted rating saved'); + } + resolve(); + } + ); + }); }); } diff --git a/src/routes/players.js b/src/routes/players.js index 85ca4d5..12df148 100644 --- a/src/routes/players.js +++ b/src/routes/players.js @@ -19,6 +19,7 @@ router.post('/api/refresh-all', async (req, res, next) => { return res.status(409).json({ error: 'Refresh already in progress' }); } refreshInProgress = true; + logger.info({ pdgaNumber: 'all' }, 'refresh-all triggered — will invoke savePlayerToDB for all players (INSERT OR REPLACE wipes derived columns)'); try { try { await refreshAllPlayersInDB(); @@ -253,7 +254,7 @@ router.post('/api/add-player', async (req, res) => { router.post('/api/refresh-player/:pdgaNumber', async (req, res) => { try { const { pdgaNumber } = req.params; - logger.info(`Manually refreshing player data for PDGA ${pdgaNumber}`); + logger.info({ pdgaNumber }, 'refresh-player triggered — will invoke savePlayerToDB (INSERT OR REPLACE wipes derived columns)'); const html = await fetchPlayerDataHTTP(pdgaNumber); const playerData = parsePlayerData(html, pdgaNumber); @@ -349,48 +350,45 @@ router.post('/api/refresh-round-history/:pdgaNumber', async (req, res) => { const isIncremental = !!sinceDate; - logger.info(`${isIncremental ? 'Incrementally updating' : 'Fully refreshing'} round history for PDGA ${pdgaNumber}${sinceDate ? ` since ${sinceDate.toDateString()}` : ''}`); + logger.info({ pdgaNumber, lastRoundUpdate, isIncremental }, 'refresh-round-history started'); browser = await launchBrowser(); - + let officialHistory; try { officialHistory = await getOfficialRatingHistory(browser, pdgaNumber); if (officialHistory.length > 0) { await saveRatingHistoryToDB(pdgaNumber, officialHistory); } + logger.info({ pdgaNumber, step: 'official_history_scrape', success: officialHistory.length > 0, count: officialHistory.length }, 'official history scrape completed'); } catch (historyError) { - logger.error('Failed to fetch official history:', historyError.message); + logger.warn({ pdgaNumber, step: 'official_history_scrape', success: false, error: historyError.message }, 'official history scrape failed'); officialHistory = []; } - + let allRounds = []; try { - logger.info(`Using optimized approach: /details + new tournaments only for PDGA ${pdgaNumber}...`); allRounds = await getOptimizedPlayerRounds(browser, pdgaNumber); - + if (allRounds.length > 0) { const roundsForDB = allRounds.map(round => ({ rating: round.rating, date: round.date, competition: round.competition })); - + await saveRoundHistoryToDB(pdgaNumber, roundsForDB, false); - logger.info(`✓ Saved ${allRounds.length} rounds using optimized approach`); - await updateLastRoundUpdateDate(pdgaNumber); - } else { - logger.info('ℹ No rounds found'); } + logger.info({ pdgaNumber, step: 'rounds_scrape_save', success: allRounds.length > 0, count: allRounds.length, lastRoundUpdateTouched: allRounds.length > 0 }, 'rounds scrape and save completed'); } catch (detailsError) { - logger.error('Failed to fetch rounds using optimized approach:', detailsError.message); + logger.warn({ pdgaNumber, step: 'rounds_scrape_save', success: false, error: detailsError.message }, 'rounds scrape and save failed'); allRounds = []; } - + await browser.close(); browser = null; - + const dbRounds = await getRoundHistoryFromDB(pdgaNumber); const roundsForPrediction = dbRounds.map(round => ({ rating: round.rating, @@ -398,9 +396,10 @@ router.post('/api/refresh-round-history/:pdgaNumber', async (req, res) => { competition: round.competition_name })); - const result = calculatePredictedRating(roundsForPrediction); + const result = calculatePredictedRating(roundsForPrediction, { pdgaNumber, callsite: 'refresh-round-history' }); + logger.info({ pdgaNumber, step: 'predicted_calc', rating: result.rating, stdDev: result.stdDev, excludedRoundsCount: result.excludedRoundsCount }, 'predicted rating calculation step completed'); - await savePredictedRatingToDB(pdgaNumber, result.rating, result.stdDev, result.excludedRoundsCount, result.cutoffRating); + await savePredictedRatingToDB(pdgaNumber, result.rating, result.stdDev, result.excludedRoundsCount, result.cutoffRating, 'refresh-round-history'); const officialCount = allRounds.filter(r => r.source === 'official').length; const newCount = allRounds.filter(r => r.source === 'new').length; @@ -418,10 +417,8 @@ router.post('/api/refresh-round-history/:pdgaNumber', async (req, res) => { message: `Used /details (${officialCount} rounds) + new tournaments (${newCount} rounds)` }); } catch (error) { - logger.error(`=== Error refreshing round history for PDGA ${pdgaNumber} ===`); - logger.error('Error type:', error.constructor.name); - logger.error('Error message:', error.message); - + logger.error({ pdgaNumber, step: 'unknown_or_orchestration', errorType: error.constructor.name, errorMessage: error.message }, 'refresh-round-history failed'); + if (browser) { try { await browser.close(); @@ -429,14 +426,14 @@ router.post('/api/refresh-round-history/:pdgaNumber', async (req, res) => { logger.error('Error closing browser:', closeError.message); } } - - res.status(500).json({ + + res.status(500).json({ error: 'Failed to refresh round history', details: error.message, errorType: error.constructor.name, timestamp: new Date().toISOString(), - suggestion: error.message.includes('socket hang up') ? - 'Rate limited by PDGA - try again in a few minutes.' : + suggestion: error.message.includes('socket hang up') ? + 'Rate limited by PDGA - try again in a few minutes.' : error.message.includes('timeout') ? 'PDGA pages are loading slowly - try again later.' : 'Tournament scraping failed - check server logs for details' @@ -444,6 +441,45 @@ router.post('/api/refresh-round-history/:pdgaNumber', async (req, res) => { } }); +router.get('/api/admin/player-state/:pdgaNumber', async (req, res) => { + const { pdgaNumber } = req.params; + try { + const player = await getPlayerFromDB(pdgaNumber); + if (!player) { + return res.status(404).json({ error: 'Player not found', pdgaNumber: parseInt(pdgaNumber) }); + } + const rounds = await getRoundHistoryFromDB(pdgaNumber); + const now = new Date(); + const twelveMonthsAgo = new Date(now); twelveMonthsAgo.setFullYear(now.getFullYear() - 1); + const twentyFourMonthsAgo = new Date(now); twentyFourMonthsAgo.setFullYear(now.getFullYear() - 2); + + const roundsInLast12mo = rounds.filter(r => new Date(r.date) >= twelveMonthsAgo).length; + const roundsInLast24mo = rounds.filter(r => new Date(r.date) >= twentyFourMonthsAgo).length; + const dates = rounds.map(r => r.date).sort(); + + res.json({ + pdgaNumber: player.pdga_number, + name: player.name, + currentRating: player.current_rating, + ratingChange: player.rating_change, + predictedRating: player.predicted_rating, + stdDev: player.std_dev, + excludedRoundsCount: player.excluded_rounds_count, + cutoffRating: player.cutoff_rating, + lastUpdated: player.last_updated, + lastRoundUpdate: player.last_round_update, + roundCount: rounds.length, + roundsInLast12mo, + roundsInLast24mo, + oldestRound: dates[0] ?? null, + newestRound: dates[dates.length - 1] ?? null + }); + } catch (err) { + logger.error({ err: err.message, pdgaNumber }, 'admin player-state endpoint failed'); + res.status(500).json({ error: 'Failed to fetch player state', details: err.message }); + } +}); + router.post('/api/calculate-target-rating/:pdgaNumber', async (req, res) => { const { pdgaNumber } = req.params; const pdgaNum = parseInt(pdgaNumber, 10); diff --git a/src/services/player-service.js b/src/services/player-service.js index 25bcb7d..a94b98e 100644 --- a/src/services/player-service.js +++ b/src/services/player-service.js @@ -36,22 +36,29 @@ async function getPlayerDataFromDB(pdgaNumber, { includeMonthlyHistory = true } try { const cachedPlayer = await getPlayerFromDB(pdgaNumber); if (cachedPlayer) { - logger.debug(`Loading PDGA ${pdgaNumber} from DB (source of truth)`); + logger.debug({ pdgaNumber }, 'Loading player from DB (source of truth)'); let predictedRating = cachedPlayer.predicted_rating; let stdDev = cachedPlayer.std_dev; let excludedRoundsCount = cachedPlayer.excluded_rounds_count; let cutoffRating = cachedPlayer.cutoff_rating; if (!predictedRating || predictedRating === 0) { + logger.debug({ pdgaNumber, dbValue: cachedPlayer.predicted_rating }, 'lazy recompute triggered for predicted_rating'); predictedRating = await getPredictedRatingFromDB(pdgaNumber); const updatedPlayer = await getPlayerFromDB(pdgaNumber); stdDev = updatedPlayer?.std_dev; excludedRoundsCount = updatedPlayer?.excluded_rounds_count; cutoffRating = updatedPlayer?.cutoff_rating; + if (!predictedRating || predictedRating === 0) { + logger.info({ pdgaNumber, recomputedValue: predictedRating }, 'lazy recompute did not yield a positive predicted rating'); + } } const rating = cachedPlayer.current_rating; const rawRatingChange = cachedPlayer.rating_change; + if (predictedRating != null && predictedRating <= 0) { + logger.warn({ pdgaNumber, dbValue: predictedRating }, 'predicted rating present but <= 0 — rendered as empty'); + } const resolvedPredicted = predictedRating > 0 ? predictedRating : null; const resolvedStdDev = stdDev > 0 ? stdDev : null; @@ -140,22 +147,28 @@ async function scrapePDGARating(pdgaNumber, retries = 3) { async function getPredictedRatingFromDB(pdgaNumber) { try { const roundHistory = await getRoundHistoryFromDB(pdgaNumber); - if (roundHistory.length > 0) { - logger.debug(`Using ${roundHistory.length} cached rounds for PDGA ${pdgaNumber} prediction`); - - const roundRatings = roundHistory.map(round => ({ - rating: round.rating, - date: new Date(round.date), - competition: round.competition_name || 'Unknown' - })); - - const result = calculatePredictedRating(roundRatings); - - await savePredictedRatingToDB(pdgaNumber, result.rating, result.stdDev, result.excludedRoundsCount, result.cutoffRating); - - return result.rating; + if (roundHistory.length === 0) { + logger.info({ pdgaNumber, reason: 'no_round_history_in_db' }, 'predicted recompute returning 0 — no round history available'); + return 0; } - return 0; + + logger.debug({ pdgaNumber, cachedRounds: roundHistory.length }, 'Using cached rounds for prediction'); + + const roundRatings = roundHistory.map(round => ({ + rating: round.rating, + date: new Date(round.date), + competition: round.competition_name || 'Unknown' + })); + + const result = calculatePredictedRating(roundRatings, { pdgaNumber, callsite: 'getPredictedRatingFromDB' }); + + if (result.rating === 0) { + logger.warn({ pdgaNumber, roundsInDb: roundHistory.length }, 'predicted recompute returned 0 despite having rounds in DB'); + } + + await savePredictedRatingToDB(pdgaNumber, result.rating, result.stdDev, result.excludedRoundsCount, result.cutoffRating, 'lazy-recompute'); + + return result.rating; } catch (err) { logger.error(`Error getting predicted rating from DB for ${pdgaNumber}:`, err.message); return 0; diff --git a/src/services/rating-calculator.js b/src/services/rating-calculator.js index 576427f..9c6a3e0 100644 --- a/src/services/rating-calculator.js +++ b/src/services/rating-calculator.js @@ -1,3 +1,5 @@ +const logger = require('../logger'); + function parseDate(dateStr) { const multiDayMatch = dateStr.match(/^(\d{1,2})(-([A-Za-z]{3}))?(\s+to\s+)(\d{1,2})-([A-Za-z]{3})-(\d{4})$/); if (multiDayMatch) { @@ -79,15 +81,19 @@ function calculateStandardDeviation(ratings) { return Math.sqrt(variance); } -function calculatePredictedRating(roundRatings) { +function calculatePredictedRating(roundRatings, context = {}) { + const pdgaNumber = context.pdgaNumber ?? null; + const callsite = context.callsite ?? 'unknown'; const debugLog = []; debugLog.push('=== PDGA RATING CALCULATION (Following Official Rules) ==='); if (!roundRatings || roundRatings.length === 0) { debugLog.push('❌ No rounds provided for prediction'); + logger.warn({ pdgaNumber, callsite, reason: 'no_rounds' }, 'predicted rating computed as 0'); return { rating: 0, debugLog, excludedRoundsCount: null, cutoffRating: null }; } + logger.info({ pdgaNumber, callsite, inputRounds: roundRatings.length }, 'predicted rating calculation started'); debugLog.push(`📊 Starting with ${roundRatings.length} total rounds`); const nextUpdateDate = getNextPDGAUpdateDate(); @@ -100,6 +106,7 @@ function calculatePredictedRating(roundRatings) { if (allSortedRounds.length === 0) { debugLog.push('❌ No valid rounds after filtering for update date'); + logger.warn({ pdgaNumber, callsite, reason: 'no_rounds_after_date_filter', inputRounds: roundRatings.length, nextUpdateDate: nextUpdateDate.toISOString() }, 'predicted rating computed as 0'); return { rating: 0, debugLog, excludedRoundsCount: null, cutoffRating: null }; } @@ -117,8 +124,9 @@ function calculatePredictedRating(roundRatings) { debugLog.push('🗓️ 12-MONTH FILTERING:'); debugLog.push(`✅ Rounds in last 12 months: ${eligibleRounds.length}`); + let twentyFourMonthsBeforeUpdate = null; if (eligibleRounds.length < 8) { - const twentyFourMonthsBeforeUpdate = new Date(nextUpdateDate); + twentyFourMonthsBeforeUpdate = new Date(nextUpdateDate); twentyFourMonthsBeforeUpdate.setFullYear(twentyFourMonthsBeforeUpdate.getFullYear() - 2); eligibleRounds = allSortedRounds.filter(r => r.date >= twentyFourMonthsBeforeUpdate); @@ -127,6 +135,7 @@ function calculatePredictedRating(roundRatings) { if (eligibleRounds.length === 0) { debugLog.push('❌ No eligible rounds found'); + logger.warn({ pdgaNumber, callsite, reason: 'no_eligible_rounds', afterDateFilter: allSortedRounds.length, twelveMonthCutoff: twelveMonthsBeforeUpdate.toISOString(), twentyFourMonthCutoff: twentyFourMonthsBeforeUpdate ? twentyFourMonthsBeforeUpdate.toISOString() : null }, 'predicted rating computed as 0'); return { rating: 0, debugLog, excludedRoundsCount: null, cutoffRating: null }; } @@ -235,6 +244,19 @@ function calculatePredictedRating(roundRatings) { debugLog.push(` Final Rating: ${finalRating}`); debugLog.push('=== END PDGA CALCULATION ==='); + logger.info({ + pdgaNumber, + callsite, + finalRating, + inputRounds: roundRatings.length, + afterDateFilter: allSortedRounds.length, + eligibleRounds: eligibleRounds.length, + outlierExclusionApplied: workingRatings.length >= 7, + doubleWeightingApplied: workingRatings.length >= 9, + excludedRoundsCount, + cutoffRating + }, 'predicted rating calculated'); + return { rating: finalRating, stdDev: Math.round(stdDev), debugLog, excludedRoundsCount, cutoffRating }; } diff --git a/src/services/target-rating-calculator.js b/src/services/target-rating-calculator.js index a8e5054..94d7f5b 100644 --- a/src/services/target-rating-calculator.js +++ b/src/services/target-rating-calculator.js @@ -8,7 +8,7 @@ function calculateRequiredAverage(roundRatings, targetRating, numRounds) { throw err; } - const currentPredicted = calculatePredictedRating(roundRatings).rating; + const currentPredicted = calculatePredictedRating(roundRatings, { callsite: 'target-rating-calculator' }).rating; const nextUpdate = getNextPDGAUpdateDate(); const syntheticDate = new Date(nextUpdate.getTime() - 24 * 60 * 60 * 1000);