chore: address review feedback on predicted rating logging (#11)

- align diagnostic endpoint date windows with getNextPDGAUpdateDate
- pass pdgaNumber to initial target-rating calculation for log attribution
- avoid double log when lazy-recompute returns 0
- log full error object in admin endpoint catch

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();
+        }
+      );
+    });
   });
 }
 

src/routes/players.js

@@ -7,7 +7,7 @@ const { getOfficialRatingHistory, getOptimizedPlayerRounds } = require('../scrap
 const { launchBrowser } = require('../scrapers/browser');
 const { getPlayerDataFromDB, scrapePDGARating, getAllRatingsFromDB, refreshAllPlayersInDB, getPredictedRatingFromDB, formatDisplayDate } = require('../services/player-service');
 const { getTopbarLocals } = require('../services/topbar-service');
-const { calculatePredictedRating } = require('../services/rating-calculator');
+const { calculatePredictedRating, getNextPDGAUpdateDate } = require('../services/rating-calculator');
 const { calculateRequiredAverage } = require('../services/target-rating-calculator');
 const logger = require('../logger');
 
@@ -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,46 @@ 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 cutoff = getNextPDGAUpdateDate();
+    const twelveMonthsAgo = new Date(cutoff); twelveMonthsAgo.setFullYear(cutoff.getFullYear() - 1);
+    const twentyFourMonthsAgo = new Date(cutoff); twentyFourMonthsAgo.setFullYear(cutoff.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,
+      cutoffDate: cutoff.toISOString(),
+      roundCount: rounds.length,
+      roundsInLast12mo,
+      roundsInLast24mo,
+      oldestRound: dates[0] ?? null,
+      newestRound: dates[dates.length - 1] ?? null
+    });
+  } catch (err) {
+    logger.error({ err, 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);
@@ -483,7 +520,7 @@ router.post('/api/calculate-target-rating/:pdgaNumber', async (req, res) => {
       competition: r.competition_name
     }));
 
-    const result = calculateRequiredAverage(roundRatings, target, numRounds);
+    const result = calculateRequiredAverage(roundRatings, target, numRounds, pdgaNum);
 
     logger.info(`Target rating calc for PDGA ${pdgaNum}: target=${target} rounds=${numRounds} -> avg=${result.requiredAverage}`);
 

src/services/player-service.js

@@ -36,22 +36,32 @@ 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;
+      let recomputeAttempted = false;
       if (!predictedRating || predictedRating === 0) {
+        recomputeAttempted = true;
+        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;
+      // Only warn about ≤0 if it wasn't already explained by a failed recompute (which has its own log)
+      if (!recomputeAttempted && predictedRating != null && predictedRating <= 0) {
+        logger.warn({ pdgaNumber, dbValue: predictedRating }, 'predicted rating present but <= 0 in DB without recompute — rendered as empty');
+      }
       const resolvedPredicted = predictedRating > 0 ? predictedRating : null;
       const resolvedStdDev = stdDev > 0 ? stdDev : null;
 
@@ -140,22 +150,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;

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 };
 }
 

src/services/target-rating-calculator.js

@@ -1,14 +1,14 @@
 const { calculatePredictedRating, getNextPDGAUpdateDate } = require('./rating-calculator');
 const logger = require('../logger');
 
-function calculateRequiredAverage(roundRatings, targetRating, numRounds) {
+function calculateRequiredAverage(roundRatings, targetRating, numRounds, pdgaNumber) {
   if (!Array.isArray(roundRatings) || roundRatings.length === 0) {
     const err = new Error('No round history');
     err.code = 'NO_ROUNDS';
     throw err;
   }
 
-  const currentPredicted = calculatePredictedRating(roundRatings).rating;
+  const currentPredicted = calculatePredictedRating(roundRatings, { pdgaNumber, callsite: 'target-rating-calculator' }).rating;
   const nextUpdate = getNextPDGAUpdateDate();
   const syntheticDate = new Date(nextUpdate.getTime() - 24 * 60 * 60 * 1000);