From 6ac32457a93d84a878c456200f45bb7ee2ef0785 Mon Sep 17 00:00:00 2001 From: Samuel Enocsson Date: Sat, 21 Feb 2026 15:56:57 +0100 Subject: [PATCH] feat: Add Pino structured logging, release-please CI/CD and Docker pipeline Replace all console.log/error with Pino logger (info/warn/error/debug/fatal) for structured JSON logging in production and pretty-print in development. Remove redundant header dumps and consolidate rate-limit logging. Add GitHub Actions workflow with release-please for automated semver releases and Docker build/push to GHCR on new releases. --- .github/workflows/release-please.yml | 52 ++++++ .release-please-manifest.json | 3 + package-lock.json | 238 ++++++++++++++++++++++++++- package.json | 4 +- release-please-config.json | 13 ++ server.js | 5 +- src/db.js | 47 +++--- src/logger.js | 10 ++ src/routes/courses.js | 53 +++--- src/routes/players.js | 81 ++++----- src/scrapers/course-puppeteer.js | 37 +++-- src/scrapers/player-http.js | 66 +++----- src/scrapers/player-puppeteer.js | 39 ++--- src/services/player-service.js | 39 ++--- 14 files changed, 498 insertions(+), 189 deletions(-) create mode 100644 .github/workflows/release-please.yml create mode 100644 .release-please-manifest.json create mode 100644 release-please-config.json create mode 100644 src/logger.js diff --git a/.github/workflows/release-please.yml b/.github/workflows/release-please.yml new file mode 100644 index 0000000..59c3d43 --- /dev/null +++ b/.github/workflows/release-please.yml @@ -0,0 +1,52 @@ +name: Release Please +on: + push: + branches: [main] + +permissions: + contents: write + pull-requests: write + +jobs: + release-please: + runs-on: ubuntu-latest + outputs: + release_created: ${{ steps.release.outputs.release_created }} + tag_name: ${{ steps.release.outputs.tag_name }} + steps: + - uses: googleapis/release-please-action@v4 + id: release + with: + release-type: node + + docker: + needs: release-please + if: ${{ needs.release-please.outputs.release_created }} + runs-on: ubuntu-latest + permissions: + contents: read + packages: write + steps: + - uses: actions/checkout@v4 + + - uses: docker/login-action@v3 + with: + registry: ghcr.io + username: ${{ github.actor }} + password: ${{ secrets.GITHUB_TOKEN }} + + - uses: docker/metadata-action@v5 + id: meta + with: + images: ghcr.io/${{ github.repository }} + tags: | + type=semver,pattern={{version}},value=${{ needs.release-please.outputs.tag_name }} + type=semver,pattern={{major}}.{{minor}},value=${{ needs.release-please.outputs.tag_name }} + type=raw,value=latest + + - uses: docker/build-push-action@v6 + with: + context: . + push: true + tags: ${{ steps.meta.outputs.tags }} + labels: ${{ steps.meta.outputs.labels }} diff --git a/.release-please-manifest.json b/.release-please-manifest.json new file mode 100644 index 0000000..37fcefa --- /dev/null +++ b/.release-please-manifest.json @@ -0,0 +1,3 @@ +{ + ".": "1.0.0" +} diff --git a/package-lock.json b/package-lock.json index 34c3ff1..639d131 100644 --- a/package-lock.json +++ b/package-lock.json @@ -11,13 +11,15 @@ "ejs": "^4.0.1", "express": "^4.18.2", "fs": "^0.0.1-security", + "pino": "^10.3.1", "puppeteer": "^21.0.0", "puppeteer-extra": "^3.3.6", "puppeteer-extra-plugin-stealth": "^2.11.2", "sqlite3": "^5.1.7" }, "devDependencies": { - "nodemon": "^3.0.1" + "nodemon": "^3.0.1", + "pino-pretty": "^13.1.3" } }, "node_modules/@babel/code-frame": { @@ -72,6 +74,12 @@ "node": ">=10" } }, + "node_modules/@pinojs/redact": { + "version": "0.4.0", + "resolved": "https://registry.npmjs.org/@pinojs/redact/-/redact-0.4.0.tgz", + "integrity": "sha512-k2ENnmBugE/rzQfEcdWHcCY+/FM3VLzH9cYEsbdsoqrvzAKRhUZeRNhAZvB8OitQJ1TBed3yqWtdjzS6wJKBwg==", + "license": "MIT" + }, "node_modules/@puppeteer/browsers": { "version": "1.9.1", "license": "Apache-2.0", @@ -294,6 +302,15 @@ "integrity": "sha512-htCUDlxyyCLMgaM3xXg0C0LW2xqfuQ6p05pCEIsXuyQ+a1koYKTuBMzRNwmybfLgvJDMd0r1LTn4+E0Ti6C2AA==", "license": "MIT" }, + "node_modules/atomic-sleep": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/atomic-sleep/-/atomic-sleep-1.0.0.tgz", + "integrity": "sha512-kNOjDqAh7px0XWNI+4QbzoiR/nTkHAWNud2uvnJquD1/x5a7EQZMJT0AczqK0Qn67oY/TTQ1LbUKajZpp3I9tQ==", + "license": "MIT", + "engines": { + "node": ">=8.0.0" + } + }, "node_modules/b4a": { "version": "1.6.7", "license": "Apache-2.0" @@ -620,6 +637,13 @@ "color-support": "bin.js" } }, + "node_modules/colorette": { + "version": "2.0.20", + "resolved": "https://registry.npmjs.org/colorette/-/colorette-2.0.20.tgz", + "integrity": "sha512-IfEDxwoWIjkeXL1eXcDiow4UbKjhLdq6/EuSVR9GMN7KVH3r9gQ83e73hsz1Nd1T3ijd5xv1wcWRYO+D6kCI2w==", + "dev": true, + "license": "MIT" + }, "node_modules/concat-map": { "version": "0.0.1", "license": "MIT" @@ -697,6 +721,16 @@ "node": ">= 14" } }, + "node_modules/dateformat": { + "version": "4.6.3", + "resolved": "https://registry.npmjs.org/dateformat/-/dateformat-4.6.3.tgz", + "integrity": "sha512-2P0p0pFGzHS5EMnhdxQi7aJN+iMheud0UhG4dlE1DLAlvL8JHjJJTX/CSm4JXwV0Ka5nGk3zC5mcb5bUQUxxMA==", + "dev": true, + "license": "MIT", + "engines": { + "node": "*" + } + }, "node_modules/debug": { "version": "2.6.9", "license": "MIT", @@ -1053,10 +1087,24 @@ "version": "2.1.3", "license": "MIT" }, + "node_modules/fast-copy": { + "version": "4.0.2", + "resolved": "https://registry.npmjs.org/fast-copy/-/fast-copy-4.0.2.tgz", + "integrity": "sha512-ybA6PDXIXOXivLJK/z9e+Otk7ve13I4ckBvGO5I2RRmBU1gMHLVDJYEuJYhGwez7YNlYji2M2DvVU+a9mSFDlw==", + "dev": true, + "license": "MIT" + }, "node_modules/fast-fifo": { "version": "1.3.2", "license": "MIT" }, + "node_modules/fast-safe-stringify": { + "version": "2.1.1", + "resolved": "https://registry.npmjs.org/fast-safe-stringify/-/fast-safe-stringify-2.1.1.tgz", + "integrity": "sha512-W+KJc2dmILlPplD/H4K9l9LcAHAfPtP6BY84uVLXQ6Evcz9Lcg33Y2z1IVblT6xdY54PXYVHEv+0Wpq8Io6zkA==", + "dev": true, + "license": "MIT" + }, "node_modules/fd-slicer": { "version": "1.1.0", "license": "MIT", @@ -1417,6 +1465,13 @@ "node": ">= 0.4" } }, + "node_modules/help-me": { + "version": "5.0.0", + "resolved": "https://registry.npmjs.org/help-me/-/help-me-5.0.0.tgz", + "integrity": "sha512-7xgomUX6ADmcYzFik0HzAxh/73YlKR9bmFzf51CZwR+b6YtzU2m0u49hQCqV6SvlqIqsaxovfwdvbnsw3b/zpg==", + "dev": true, + "license": "MIT" + }, "node_modules/http-cache-semantics": { "version": "4.2.0", "resolved": "https://registry.npmjs.org/http-cache-semantics/-/http-cache-semantics-4.2.0.tgz", @@ -1733,6 +1788,16 @@ "node": ">=10" } }, + "node_modules/joycon": { + "version": "3.1.1", + "resolved": "https://registry.npmjs.org/joycon/-/joycon-3.1.1.tgz", + "integrity": "sha512-34wB/Y7MW7bzjKRjUKTa46I2Z7eV62Rkhva+KkopW7Qvv/OSWBqvkSY7vusOPrNuZcUG3tApvdVgNB8POj3SPw==", + "dev": true, + "license": "MIT", + "engines": { + "node": ">=10" + } + }, "node_modules/js-tokens": { "version": "4.0.0", "license": "MIT" @@ -2339,6 +2404,15 @@ "url": "https://github.com/sponsors/ljharb" } }, + "node_modules/on-exit-leak-free": { + "version": "2.1.2", + "resolved": "https://registry.npmjs.org/on-exit-leak-free/-/on-exit-leak-free-2.1.2.tgz", + "integrity": "sha512-0eJJY6hXLGf1udHwfNftBqH+g73EU4B504nZeKpz1sYRKafAghwxEJunB2O7rDZkL4PGfsMVnTXZ2EjibbqcsA==", + "license": "MIT", + "engines": { + "node": ">=14.0.0" + } + }, "node_modules/on-finished": { "version": "2.4.1", "license": "MIT", @@ -2484,6 +2558,81 @@ "url": "https://github.com/sponsors/jonschlinkert" } }, + "node_modules/pino": { + "version": "10.3.1", + "resolved": "https://registry.npmjs.org/pino/-/pino-10.3.1.tgz", + "integrity": "sha512-r34yH/GlQpKZbU1BvFFqOjhISRo1MNx1tWYsYvmj6KIRHSPMT2+yHOEb1SG6NMvRoHRF0a07kCOox/9yakl1vg==", + "license": "MIT", + "dependencies": { + "@pinojs/redact": "^0.4.0", + "atomic-sleep": "^1.0.0", + "on-exit-leak-free": "^2.1.0", + "pino-abstract-transport": "^3.0.0", + "pino-std-serializers": "^7.0.0", + "process-warning": "^5.0.0", + "quick-format-unescaped": "^4.0.3", + "real-require": "^0.2.0", + "safe-stable-stringify": "^2.3.1", + "sonic-boom": "^4.0.1", + "thread-stream": "^4.0.0" + }, + "bin": { + "pino": "bin.js" + } + }, + "node_modules/pino-abstract-transport": { + "version": "3.0.0", + "resolved": "https://registry.npmjs.org/pino-abstract-transport/-/pino-abstract-transport-3.0.0.tgz", + "integrity": "sha512-wlfUczU+n7Hy/Ha5j9a/gZNy7We5+cXp8YL+X+PG8S0KXxw7n/JXA3c46Y0zQznIJ83URJiwy7Lh56WLokNuxg==", + "license": "MIT", + "dependencies": { + "split2": "^4.0.0" + } + }, + "node_modules/pino-pretty": { + "version": "13.1.3", + "resolved": "https://registry.npmjs.org/pino-pretty/-/pino-pretty-13.1.3.tgz", + "integrity": "sha512-ttXRkkOz6WWC95KeY9+xxWL6AtImwbyMHrL1mSwqwW9u+vLp/WIElvHvCSDg0xO/Dzrggz1zv3rN5ovTRVowKg==", + "dev": true, + "license": "MIT", + "dependencies": { + "colorette": "^2.0.7", + "dateformat": "^4.6.3", + "fast-copy": "^4.0.0", + "fast-safe-stringify": "^2.1.1", + "help-me": "^5.0.0", + "joycon": "^3.1.1", + "minimist": "^1.2.6", + "on-exit-leak-free": "^2.1.0", + "pino-abstract-transport": "^3.0.0", + "pump": "^3.0.0", + "secure-json-parse": "^4.0.0", + "sonic-boom": "^4.0.1", + "strip-json-comments": "^5.0.2" + }, + "bin": { + "pino-pretty": "bin.js" + } + }, + "node_modules/pino-pretty/node_modules/strip-json-comments": { + "version": "5.0.3", + "resolved": "https://registry.npmjs.org/strip-json-comments/-/strip-json-comments-5.0.3.tgz", + "integrity": "sha512-1tB5mhVo7U+ETBKNf92xT4hrQa3pm0MZ0PQvuDnWgAAGHDsfp4lPSpiS6psrSiet87wyGPh9ft6wmhOMQ0hDiw==", + "dev": true, + "license": "MIT", + "engines": { + "node": ">=14.16" + }, + "funding": { + "url": "https://github.com/sponsors/sindresorhus" + } + }, + "node_modules/pino-std-serializers": { + "version": "7.1.0", + "resolved": "https://registry.npmjs.org/pino-std-serializers/-/pino-std-serializers-7.1.0.tgz", + "integrity": "sha512-BndPH67/JxGExRgiX1dX0w1FvZck5Wa4aal9198SrRhZjH3GxKQUKIBnYJTdj2HDN3UQAS06HlfcSbQj2OHmaw==", + "license": "MIT" + }, "node_modules/prebuild-install": { "version": "7.1.3", "resolved": "https://registry.npmjs.org/prebuild-install/-/prebuild-install-7.1.3.tgz", @@ -2544,6 +2693,22 @@ "node": ">=6" } }, + "node_modules/process-warning": { + "version": "5.0.0", + "resolved": "https://registry.npmjs.org/process-warning/-/process-warning-5.0.0.tgz", + "integrity": "sha512-a39t9ApHNx2L4+HBnQKqxxHNs1r7KF+Intd8Q/g1bUh6q0WIp9voPXJ/x0j+ZL45KF1pJd9+q2jLIRMfvEshkA==", + "funding": [ + { + "type": "github", + "url": "https://github.com/sponsors/fastify" + }, + { + "type": "opencollective", + "url": "https://opencollective.com/fastify" + } + ], + "license": "MIT" + }, "node_modules/progress": { "version": "2.0.3", "license": "MIT", @@ -2950,6 +3115,12 @@ "url": "https://github.com/sponsors/ljharb" } }, + "node_modules/quick-format-unescaped": { + "version": "4.0.4", + "resolved": "https://registry.npmjs.org/quick-format-unescaped/-/quick-format-unescaped-4.0.4.tgz", + "integrity": "sha512-tYC1Q1hgyRuHgloV/YXs2w15unPVh8qfu/qCTfhTYamaw7fyhumKa2yGpdSo87vY32rIclj+4fWYQXUMs9EHvg==", + "license": "MIT" + }, "node_modules/range-parser": { "version": "1.2.1", "license": "MIT", @@ -3010,6 +3181,15 @@ "node": ">=8.10.0" } }, + "node_modules/real-require": { + "version": "0.2.0", + "resolved": "https://registry.npmjs.org/real-require/-/real-require-0.2.0.tgz", + "integrity": "sha512-57frrGM/OCTLqLOAh0mhVA9VBMHd+9U7Zb2THMGdBUoZVOtGbJzjxsYGDJ3A9AYYCP4hn6y1TVbaOfzWtm5GFg==", + "license": "MIT", + "engines": { + "node": ">= 12.13.0" + } + }, "node_modules/require-directory": { "version": "2.1.1", "license": "MIT", @@ -3068,10 +3248,36 @@ ], "license": "MIT" }, + "node_modules/safe-stable-stringify": { + "version": "2.5.0", + "resolved": "https://registry.npmjs.org/safe-stable-stringify/-/safe-stable-stringify-2.5.0.tgz", + "integrity": "sha512-b3rppTKm9T+PsVCBEOUR46GWI7fdOs00VKZ1+9c1EWDaDMvjQc6tUwuFyIprgGgTcWoVHSKrU8H31ZHA2e0RHA==", + "license": "MIT", + "engines": { + "node": ">=10" + } + }, "node_modules/safer-buffer": { "version": "2.1.2", "license": "MIT" }, + "node_modules/secure-json-parse": { + "version": "4.1.0", + "resolved": "https://registry.npmjs.org/secure-json-parse/-/secure-json-parse-4.1.0.tgz", + "integrity": "sha512-l4KnYfEyqYJxDwlNVyRfO2E4NTHfMKAWdUuA8J0yve2Dz/E/PdBepY03RvyJpssIpRFwJoCD55wA+mEDs6ByWA==", + "dev": true, + "funding": [ + { + "type": "github", + "url": "https://github.com/sponsors/fastify" + }, + { + "type": "opencollective", + "url": "https://opencollective.com/fastify" + } + ], + "license": "BSD-3-Clause" + }, "node_modules/semver": { "version": "7.7.2", "license": "ISC", @@ -3353,6 +3559,15 @@ "version": "2.1.3", "license": "MIT" }, + "node_modules/sonic-boom": { + "version": "4.2.1", + "resolved": "https://registry.npmjs.org/sonic-boom/-/sonic-boom-4.2.1.tgz", + "integrity": "sha512-w6AxtubXa2wTXAUsZMMWERrsIRAdrK0Sc+FUytWvYAhBJLyuI4llrMIC1DtlNSdI99EI86KZum2MMq3EAZlF9Q==", + "license": "MIT", + "dependencies": { + "atomic-sleep": "^1.0.0" + } + }, "node_modules/source-map": { "version": "0.6.1", "license": "BSD-3-Clause", @@ -3361,6 +3576,15 @@ "node": ">=0.10.0" } }, + "node_modules/split2": { + "version": "4.2.0", + "resolved": "https://registry.npmjs.org/split2/-/split2-4.2.0.tgz", + "integrity": "sha512-UcjcJOWknrNkF6PLX83qcHM6KHgVKNkV62Y8a5uYDVv9ydGQVwAHMKqHdJje1VTWpljG0WYpCDhrCdAOYH4TWg==", + "license": "ISC", + "engines": { + "node": ">= 10.x" + } + }, "node_modules/sqlite3": { "version": "5.1.7", "resolved": "https://registry.npmjs.org/sqlite3/-/sqlite3-5.1.7.tgz", @@ -3518,6 +3742,18 @@ "b4a": "^1.6.4" } }, + "node_modules/thread-stream": { + "version": "4.0.0", + "resolved": "https://registry.npmjs.org/thread-stream/-/thread-stream-4.0.0.tgz", + "integrity": "sha512-4iMVL6HAINXWf1ZKZjIPcz5wYaOdPhtO8ATvZ+Xqp3BTdaqtAwQkNmKORqcIo5YkQqGXq5cwfswDwMqqQNrpJA==", + "license": "MIT", + "dependencies": { + "real-require": "^0.2.0" + }, + "engines": { + "node": ">=20" + } + }, "node_modules/through": { "version": "2.3.8", "license": "MIT" diff --git a/package.json b/package.json index 7c46a83..f0c1a63 100644 --- a/package.json +++ b/package.json @@ -11,12 +11,14 @@ "ejs": "^4.0.1", "express": "^4.18.2", "fs": "^0.0.1-security", + "pino": "^10.3.1", "puppeteer": "^21.0.0", "puppeteer-extra": "^3.3.6", "puppeteer-extra-plugin-stealth": "^2.11.2", "sqlite3": "^5.1.7" }, "devDependencies": { - "nodemon": "^3.0.1" + "nodemon": "^3.0.1", + "pino-pretty": "^13.1.3" } } diff --git a/release-please-config.json b/release-please-config.json new file mode 100644 index 0000000..1e0bb84 --- /dev/null +++ b/release-please-config.json @@ -0,0 +1,13 @@ +{ + "packages": { + ".": { + "release-type": "node", + "changelog-sections": [ + { "type": "feat", "section": "Features" }, + { "type": "fix", "section": "Bug Fixes" }, + { "type": "chore", "section": "Miscellaneous" }, + { "type": "refactor", "section": "Code Refactoring" } + ] + } + } +} diff --git a/server.js b/server.js index f5df138..7747255 100644 --- a/server.js +++ b/server.js @@ -5,6 +5,7 @@ const { initializeDatabase, checkAndPopulateDatabase } = require('./src/db'); const playerRoutes = require('./src/routes/players'); const courseRoutes = require('./src/routes/courses'); const pageRoutes = require('./src/routes/pages'); +const logger = require('./src/logger'); const app = express(); const PORT = 3000; @@ -22,9 +23,9 @@ initializeDatabase().then(async () => { await checkAndPopulateDatabase(); app.listen(PORT, () => { - console.log(`PDGA Ratings app running on http://localhost:${PORT}`); + logger.info(`PDGA Ratings app running on http://localhost:${PORT}`); }); }).catch(err => { - console.error('Failed to initialize database:', err); + logger.fatal('Failed to initialize database:', err); process.exit(1); }); diff --git a/src/db.js b/src/db.js index 7be1f64..ed781fa 100644 --- a/src/db.js +++ b/src/db.js @@ -1,4 +1,5 @@ const sqlite3 = require('sqlite3').verbose(); +const logger = require('./logger'); const dbPath = process.env.DB_PATH || './ratings.db'; const db = new sqlite3.Database(dbPath); @@ -20,13 +21,13 @@ function initializeDatabase() { db.get("PRAGMA table_info(players)", (err, info) => { if (err) { - console.error('Error checking table schema:', err); + logger.error('Error checking table schema:', err); return; } db.all("PRAGMA table_info(players)", (err, columns) => { if (err) { - console.error('Error getting table info:', err); + logger.error('Error getting table info:', err); return; } @@ -35,26 +36,26 @@ function initializeDatabase() { const hasStdDev = columns.some(col => col.name === 'std_dev'); if (!hasLastRoundUpdate) { - console.log('Adding last_round_update column to players table...'); + logger.info('Adding last_round_update column to players table...'); db.run(`ALTER TABLE players ADD COLUMN last_round_update DATETIME DEFAULT NULL`, (err) => { - if (err) console.error('Error adding last_round_update column:', err.message); - else console.log('Successfully added last_round_update column'); + if (err) logger.error('Error adding last_round_update column:', err.message); + else logger.info('Successfully added last_round_update column'); }); } if (!hasPredictedRating) { - console.log('Adding predicted_rating column to players table...'); + logger.info('Adding predicted_rating column to players table...'); db.run(`ALTER TABLE players ADD COLUMN predicted_rating INTEGER DEFAULT NULL`, (err) => { - if (err) console.error('Error adding predicted_rating column:', err.message); - else console.log('Successfully added predicted_rating column'); + if (err) logger.error('Error adding predicted_rating column:', err.message); + else logger.info('Successfully added predicted_rating column'); }); } if (!hasStdDev) { - console.log('Adding std_dev column to players table...'); + logger.info('Adding std_dev column to players table...'); db.run(`ALTER TABLE players ADD COLUMN std_dev INTEGER DEFAULT NULL`, (err) => { - if (err) console.error('Error adding std_dev column:', err.message); - else console.log('Successfully added std_dev column'); + if (err) logger.error('Error adding std_dev column:', err.message); + else logger.info('Successfully added std_dev column'); }); } }); @@ -111,7 +112,7 @@ function initializeDatabase() { db.run(`ALTER TABLE layouts ADD COLUMN rating_count INTEGER DEFAULT 0`, () => { db.run(`ALTER TABLE layouts ADD COLUMN last_calculated DATETIME`, () => { db.run(`ALTER TABLE layouts ADD COLUMN last_played DATE`, () => { - console.log('Database initialized successfully'); + logger.info('Database initialized successfully'); resolve(); }); }); @@ -136,47 +137,47 @@ async function checkAndPopulateDatabase() { }); if (playerCount > 0) { - console.log(`✓ Database already has ${playerCount} players - skipping text file import`); - console.log('📝 Note: pdga-numbers.txt is only used when database is empty'); + logger.info(`✓ Database already has ${playerCount} players - skipping text file import`); + logger.info('📝 Note: pdga-numbers.txt is only used when database is empty'); return; } - console.log('=== Database is empty - populating from PDGA numbers file ==='); + logger.info('=== Database is empty - populating from PDGA numbers file ==='); const pdgaNumbers = fs.readFileSync('pdga-numbers.txt', 'utf-8') .split('\n') .map(num => num.trim()) .filter(num => num); - console.log(`Found ${pdgaNumbers.length} PDGA numbers in file`); + logger.info(`Found ${pdgaNumbers.length} PDGA numbers in file`); if (pdgaNumbers.length === 0) { - console.log('⚠ No PDGA numbers found in file'); + logger.info('⚠ No PDGA numbers found in file'); return; } - console.log('Populating database with players from file...'); + logger.info('Populating database with players from file...'); for (let i = 0; i < pdgaNumbers.length; i++) { const pdgaNumber = pdgaNumbers[i]; - console.log(`[${i + 1}/${pdgaNumbers.length}] Adding PDGA ${pdgaNumber}...`); + logger.info(`[${i + 1}/${pdgaNumbers.length}] Adding PDGA ${pdgaNumber}...`); try { const playerData = await scrapePDGARating(pdgaNumber); - console.log(` ✓ Added ${playerData.name}`); + logger.info(` ✓ Added ${playerData.name}`); if (i < pdgaNumbers.length - 1) { await new Promise(resolve => setTimeout(resolve, 2000)); } } catch (error) { - console.error(` ✗ Failed to add PDGA ${pdgaNumber}:`, error.message); + logger.error(` ✗ Failed to add PDGA ${pdgaNumber}:`, error.message); } } - console.log('=== Database population complete ==='); + logger.info('=== Database population complete ==='); } catch (error) { - console.error('Error during database population check:', error.message); + logger.error('Error during database population check:', error.message); } } diff --git a/src/logger.js b/src/logger.js new file mode 100644 index 0000000..f429509 --- /dev/null +++ b/src/logger.js @@ -0,0 +1,10 @@ +const pino = require('pino'); + +const logger = pino({ + level: process.env.LOG_LEVEL || 'info', + transport: process.env.NODE_ENV !== 'production' + ? { target: 'pino-pretty' } + : undefined +}); + +module.exports = logger; diff --git a/src/routes/courses.js b/src/routes/courses.js index 734f601..62bb548 100644 --- a/src/routes/courses.js +++ b/src/routes/courses.js @@ -4,6 +4,7 @@ const { db } = require('../db'); const { getAllCoursesFromDB, getLayoutsForCourse, updateLayoutRating } = require('../models/course'); const { launchBrowser } = require('../scrapers/browser'); const { layoutEventCache, scrapeCourseDirectory, scrapeCourseLayouts, scrapeEventResults } = require('../scrapers/course-puppeteer'); +const logger = require('../logger'); // Request locking to prevent concurrent scrapes of the same resource const activeScrapes = new Map(); @@ -33,7 +34,7 @@ router.get('/partials/course-layouts/:courseId', async (req, res) => { const layouts = await getLayoutsForCourse(courseId); res.render('../partials/course-layouts', { layouts, courseId }); } catch (error) { - console.error('Error loading course layouts:', error.message); + logger.error('Error loading course layouts:', error.message); res.status(500).send('
Error loading layouts
'); } }); @@ -43,7 +44,7 @@ router.get('/api/courses', async (req, res) => { const courses = await getAllCoursesFromDB(); res.json(courses); } catch (error) { - console.error('Error fetching courses:', error.message); + logger.error('Error fetching courses:', error.message); res.status(500).json({ error: 'Failed to fetch courses' }); } }); @@ -54,7 +55,7 @@ router.get('/api/layouts/:courseId', async (req, res) => { const layouts = await getLayoutsForCourse(courseId); res.json(layouts); } catch (error) { - console.error('Error fetching layouts:', error.message); + logger.error('Error fetching layouts:', error.message); res.status(500).json({ error: 'Failed to fetch layouts' }); } }); @@ -65,7 +66,7 @@ router.post('/api/scrape-courses', async (req, res) => { let browser = null; try { - console.log('Starting course directory scraping...'); + logger.info('Starting course directory scraping...'); browser = await launchBrowser(); @@ -80,7 +81,7 @@ router.post('/api/scrape-courses', async (req, res) => { message: `Successfully scraped ${courses.length} courses` }); } catch (error) { - console.error('Error scraping courses:', error.message); + logger.error('Error scraping courses:', error.message); if (browser) { try { await browser.close(); } catch (e) {} } @@ -96,7 +97,7 @@ router.post('/api/scrape-layouts/:courseId', async (req, res) => { const lockKey = `layout-${courseId}`; if (activeScrapes.has(lockKey)) { - console.log(`⚠ī¸ Scrape already in progress for course ${courseId}`); + logger.info(`⚠ī¸ Scrape already in progress for course ${courseId}`); return res.status(409).json({ error: 'Scrape already in progress for this course', message: 'Please wait for the current scrape to complete' @@ -118,19 +119,19 @@ router.post('/api/scrape-layouts/:courseId', async (req, res) => { throw new Error('Course not found'); } - console.log(`Starting layout scraping for course: ${course.name}`); + logger.info(`Starting layout scraping for course: ${course.name}`); browser = await launchBrowser(); const layouts = await scrapeCourseLayouts(browser, course.link, courseId); - console.log(`\n=== Starting event results scraping for ${course.name} ===`); + logger.info(`\n=== Starting event results scraping for ${course.name} ===`); const courseIdInt = parseInt(courseId); const layoutData = layoutEventCache.get(courseIdInt); if (!layoutData || layoutData.length === 0) { - console.log('No event data found in cache, skipping event results scraping'); + logger.info('No event data found in cache, skipping event results scraping'); await browser.close(); browser = null; @@ -183,7 +184,7 @@ router.post('/api/scrape-layouts/:courseId', async (req, res) => { await new Promise(resolve => setTimeout(resolve, 2000)); } - console.log(`\n=== Calculating final ratings for all layouts ===`); + logger.info(`\n=== Calculating final ratings for all layouts ===`); let savedCount = 0; for (const layoutKey in allLayoutRatings) { @@ -194,10 +195,10 @@ router.post('/api/scrape-layouts/:courseId', async (req, res) => { layoutDataResult.allRatings.reduce((sum, r) => sum + r, 0) / layoutDataResult.allRatings.length ); - console.log(`Layout: ${layoutDataResult.name} (Par ${layoutDataResult.par})`); - console.log(` Total ratings collected: ${layoutDataResult.allRatings.length}`); - console.log(` Mean rating: ${meanRating}`); - console.log(` Last played: ${layoutDataResult.latestDate || 'Unknown'}`); + logger.debug(`Layout: ${layoutDataResult.name} (Par ${layoutDataResult.par})`); + logger.debug(` Total ratings collected: ${layoutDataResult.allRatings.length}`); + logger.debug(` Mean rating: ${meanRating}`); + logger.debug(` Last played: ${layoutDataResult.latestDate || 'Unknown'}`); try { const changes = await updateLayoutRating( @@ -209,11 +210,11 @@ router.post('/api/scrape-layouts/:courseId', async (req, res) => { layoutDataResult.latestDate ); if (changes > 0) { - console.log(` ✓ Updated in database`); + logger.info(` ✓ Updated in database`); savedCount++; } } catch (err) { - console.error(` Error updating layout ${layoutDataResult.name}:`, err.message); + logger.error(` Error updating layout ${layoutDataResult.name}:`, err.message); } } } @@ -229,7 +230,7 @@ router.post('/api/scrape-layouts/:courseId', async (req, res) => { message: `Successfully scraped ${layouts.length} layouts and processed ${Object.keys(eventGroups).length} events for ${course.name}` }; } catch (error) { - console.error('Error scraping layouts:', error.message); + logger.error('Error scraping layouts:', error.message); if (browser) { try { await browser.close(); } catch (e) {} } @@ -249,7 +250,7 @@ router.post('/api/scrape-layouts/:courseId', async (req, res) => { }); } finally { activeScrapes.delete(lockKey); - console.log(`✓ Released lock for course ${courseId}`); + logger.info(`✓ Released lock for course ${courseId}`); } }); @@ -317,7 +318,7 @@ router.post('/api/scrape-event-results/:courseId', async (req, res) => { await browser.close(); browser = null; - console.log(`\n=== Calculating final ratings for all layouts ===`); + logger.info(`\n=== Calculating final ratings for all layouts ===`); let savedCount = 0; for (const layoutKey in allLayoutRatings) { @@ -328,10 +329,10 @@ router.post('/api/scrape-event-results/:courseId', async (req, res) => { ld.allRatings.reduce((sum, r) => sum + r, 0) / ld.allRatings.length ); - console.log(`Layout: ${ld.name} (Par ${ld.par})`); - console.log(` Total ratings collected: ${ld.allRatings.length}`); - console.log(` Mean rating: ${meanRating}`); - console.log(` Last played: ${ld.latestDate || 'Unknown'}`); + logger.debug(`Layout: ${ld.name} (Par ${ld.par})`); + logger.debug(` Total ratings collected: ${ld.allRatings.length}`); + logger.debug(` Mean rating: ${meanRating}`); + logger.debug(` Last played: ${ld.latestDate || 'Unknown'}`); try { const changes = await updateLayoutRating( @@ -343,11 +344,11 @@ router.post('/api/scrape-event-results/:courseId', async (req, res) => { ld.latestDate ); if (changes > 0) { - console.log(` ✓ Updated in database`); + logger.info(` ✓ Updated in database`); savedCount++; } } catch (err) { - console.error(` Error updating layout ${ld.name}:`, err.message); + logger.error(` Error updating layout ${ld.name}:`, err.message); } } } @@ -360,7 +361,7 @@ router.post('/api/scrape-event-results/:courseId', async (req, res) => { message: `Processed ${Object.keys(eventGroups).length} events, updated ${savedCount} layouts` }); } catch (error) { - console.error('Error scraping event results:', error.message); + logger.error('Error scraping event results:', error.message); if (browser) { try { await browser.close(); } catch (e) {} } diff --git a/src/routes/players.js b/src/routes/players.js index 5601c30..1a44d0d 100644 --- a/src/routes/players.js +++ b/src/routes/players.js @@ -7,6 +7,7 @@ const { getOfficialRatingHistory, getOptimizedPlayerRounds } = require('../scrap const { launchBrowser } = require('../scrapers/browser'); const { getPlayerDataFromDB, scrapePDGARating, getAllRatingsFromDB, refreshAllPlayersInDB, getPredictedRatingFromDB } = require('../services/player-service'); const { calculatePredictedRating } = require('../services/rating-calculator'); +const logger = require('../logger'); router.get('/partials/ratings-table', async (req, res) => { try { @@ -28,7 +29,7 @@ router.get('/partials/player-history/:pdgaNumber', async (req, res) => { try { await saveRatingHistoryToDB(pdgaNumber, history); } catch (dbErr) { - console.error('Failed to save rating history:', dbErr.message); + logger.error('Failed to save rating history:', dbErr.message); } } @@ -40,7 +41,7 @@ router.get('/partials/player-history/:pdgaNumber', async (req, res) => { res.render('../partials/player-history', { pdgaNumber, history: formattedHistory }); } catch (error) { - console.error('Error loading player history:', error.message); + logger.error('Error loading player history:', error.message); res.status(500).send('
Error loading rating history
'); } }); @@ -92,14 +93,14 @@ router.post('/api/populate-database', (req, res) => { res.write(`data: ${JSON.stringify(progress)}\n\n`); }; - console.log('=== Starting database population from database players ==='); + logger.info('=== Starting database population from database players ==='); refreshAllPlayersInDB(progressCallback).then(ratings => { - console.log(`=== Database population complete: ${ratings.length} players refreshed ===`); + logger.info(`=== Database population complete: ${ratings.length} players refreshed ===`); res.write(`data: ${JSON.stringify({ status: 'complete', ratings, message: `Successfully refreshed ${ratings.length} players` })}\n\n`); res.end(); }).catch(error => { - console.error('Error populating database:', error); + logger.error('Error populating database:', error); res.write(`data: ${JSON.stringify({ status: 'error', message: error.message })}\n\n`); res.end(); }); @@ -155,7 +156,7 @@ router.get('/api/rating-history/:pdgaNumber', async (req, res) => { const cachedHistory = await getRatingHistoryFromDB(pdgaNumber); if (cachedHistory && cachedHistory.length > 0) { - console.log(`Using cached rating history from DB for PDGA ${pdgaNumber}`); + logger.info(`Using cached rating history from DB for PDGA ${pdgaNumber}`); const formattedHistory = cachedHistory.map(row => ({ date: row.date, rating: row.rating, @@ -173,15 +174,15 @@ router.get('/api/rating-history/:pdgaNumber', async (req, res) => { return; } - console.log(`Fetching rating history for PDGA ${pdgaNumber}...`); + logger.info(`Fetching rating history for PDGA ${pdgaNumber}...`); const html = await fetchRatingHistory(pdgaNumber); const history = parseRatingHistory(html); try { await saveRatingHistoryToDB(pdgaNumber, history); - console.log(`Saved rating history for PDGA ${pdgaNumber} to database`); + logger.info(`Saved rating history for PDGA ${pdgaNumber} to database`); } catch (dbErr) { - console.error(`Failed to save rating history to database:`, dbErr.message); + logger.error(`Failed to save rating history to database:`, dbErr.message); } res.json({ @@ -189,7 +190,7 @@ router.get('/api/rating-history/:pdgaNumber', async (req, res) => { history }); } catch (error) { - console.error('Error fetching rating history:', error.message); + logger.error('Error fetching rating history:', error.message); res.status(500).json({ error: 'Failed to fetch rating history' }); } }); @@ -198,19 +199,19 @@ router.post('/api/clear-cache', (req, res) => { try { db.run('UPDATE players SET last_updated = datetime("now", "-25 hours"), last_round_update = NULL', (err) => { if (err) { - console.error('Error clearing database cache:', err); + logger.error('Error clearing database cache:', err); res.status(500).json({ error: 'Failed to clear database cache' }); return; } - console.log('Database cache cleared - all players will be refreshed on next request'); + logger.info('Database cache cleared - all players will be refreshed on next request'); res.json({ success: true, message: 'Cache cleared - database reset' }); }); } catch (error) { - console.error('Error clearing cache:', error); + logger.error('Error clearing cache:', error); res.status(500).json({ error: 'Failed to clear cache' }); } }); @@ -218,7 +219,7 @@ router.post('/api/clear-cache', (req, res) => { router.get('/api/search-player/:pdgaNumber', async (req, res) => { try { const { pdgaNumber } = req.params; - console.log(`Searching for player with PDGA number ${pdgaNumber}`); + logger.info(`Searching for player with PDGA number ${pdgaNumber}`); const existingPlayer = await getPlayerFromDB(pdgaNumber); if (existingPlayer) { @@ -245,7 +246,7 @@ router.get('/api/search-player/:pdgaNumber', async (req, res) => { player: playerData }); } catch (error) { - console.error('Error searching for player:', error.message); + logger.error('Error searching for player:', error.message); res.status(500).json({ error: 'Failed to search for player' }); } }); @@ -258,7 +259,7 @@ router.post('/api/add-player', async (req, res) => { return res.status(400).json({ error: 'PDGA number is required' }); } - console.log(`Adding player with PDGA number ${pdgaNumber}`); + logger.info(`Adding player with PDGA number ${pdgaNumber}`); const existingPlayer = await getPlayerFromDB(pdgaNumber); if (existingPlayer) { @@ -281,14 +282,14 @@ router.post('/api/add-player', async (req, res) => { await savePlayerToDB(playerData); - console.log(`Successfully added player: ${playerData.name} (#${pdgaNumber})`); + logger.info(`Successfully added player: ${playerData.name} (#${pdgaNumber})`); res.json({ success: true, player: playerData }); } catch (error) { - console.error('Error adding player:', error.message); + logger.error('Error adding player:', error.message); res.status(500).json({ error: 'Failed to add player' }); } }); @@ -296,7 +297,7 @@ router.post('/api/add-player', async (req, res) => { router.post('/api/refresh-player/:pdgaNumber', async (req, res) => { try { const { pdgaNumber } = req.params; - console.log(`Manually refreshing player data for PDGA ${pdgaNumber}`); + logger.info(`Manually refreshing player data for PDGA ${pdgaNumber}`); const html = await fetchPlayerDataHTTP(pdgaNumber); const playerData = parsePlayerData(html, pdgaNumber); @@ -308,7 +309,7 @@ router.post('/api/refresh-player/:pdgaNumber', async (req, res) => { player: playerData }); } catch (error) { - console.error('Error refreshing player data:', error.message); + logger.error('Error refreshing player data:', error.message); res.status(500).json({ error: 'Failed to refresh player data' }); } }); @@ -316,31 +317,31 @@ router.post('/api/refresh-player/:pdgaNumber', async (req, res) => { router.post('/api/refresh-rating-history/:pdgaNumber', async (req, res) => { try { const { pdgaNumber } = req.params; - console.log(`=== Manually refreshing rating history for PDGA ${pdgaNumber} ===`); + logger.info(`=== Manually refreshing rating history for PDGA ${pdgaNumber} ===`); const startTime = Date.now(); const html = await fetchRatingHistory(pdgaNumber); const fetchTime = Date.now() - startTime; - console.log(`HTML fetch completed in ${fetchTime}ms, received ${html.length} bytes`); + logger.info(`HTML fetch completed in ${fetchTime}ms, received ${html.length} bytes`); const parseStartTime = Date.now(); const history = parseRatingHistory(html); const parseTime = Date.now() - parseStartTime; - console.log(`Parsing completed in ${parseTime}ms, found ${history.length} history entries`); + logger.info(`Parsing completed in ${parseTime}ms, found ${history.length} history entries`); if (history.length > 0) { - console.log('Sample history entries:', history.slice(0, 3)); + logger.debug({ entries: history.slice(0, 3) }, 'Sample history entries'); } else { - console.log('No history entries found. HTML sample:', html.substring(0, 500)); + logger.debug({ htmlSample: html.substring(0, 500) }, 'No history entries found'); } const dbStartTime = Date.now(); await saveRatingHistoryToDB(pdgaNumber, history); const dbTime = Date.now() - dbStartTime; - console.log(`Database save completed in ${dbTime}ms`); + logger.info(`Database save completed in ${dbTime}ms`); const formattedHistory = history.map(entry => ({ date: entry.date, @@ -348,16 +349,16 @@ router.post('/api/refresh-rating-history/:pdgaNumber', async (req, res) => { displayDate: entry.displayDate })); - console.log(`=== Rating history refresh completed for PDGA ${pdgaNumber} ===`); + logger.info(`=== Rating history refresh completed for PDGA ${pdgaNumber} ===`); res.json({ success: true, history: formattedHistory }); } catch (error) { - console.error(`=== Error refreshing rating history for PDGA ${req.params.pdgaNumber} ===`); - console.error('Error type:', error.constructor.name); - console.error('Error message:', error.message); + logger.error(`=== Error refreshing rating history for PDGA ${req.params.pdgaNumber} ===`); + logger.error('Error type:', error.constructor.name); + logger.error('Error message:', error.message); res.status(500).json({ error: 'Failed to refresh rating history', @@ -392,7 +393,7 @@ router.post('/api/refresh-round-history/:pdgaNumber', async (req, res) => { const isIncremental = !!sinceDate; - console.log(`${isIncremental ? 'Incrementally updating' : 'Fully refreshing'} round history for PDGA ${pdgaNumber}${sinceDate ? ` since ${sinceDate.toDateString()}` : ''}`); + logger.info(`${isIncremental ? 'Incrementally updating' : 'Fully refreshing'} round history for PDGA ${pdgaNumber}${sinceDate ? ` since ${sinceDate.toDateString()}` : ''}`); browser = await launchBrowser(); @@ -403,13 +404,13 @@ router.post('/api/refresh-round-history/:pdgaNumber', async (req, res) => { await saveRatingHistoryToDB(pdgaNumber, officialHistory); } } catch (historyError) { - console.error('Failed to fetch official history:', historyError.message); + logger.error('Failed to fetch official history:', historyError.message); officialHistory = []; } let allRounds = []; try { - console.log(`Using optimized approach: /details + new tournaments only for PDGA ${pdgaNumber}...`); + logger.info(`Using optimized approach: /details + new tournaments only for PDGA ${pdgaNumber}...`); allRounds = await getOptimizedPlayerRounds(browser, pdgaNumber); if (allRounds.length > 0) { @@ -420,14 +421,14 @@ router.post('/api/refresh-round-history/:pdgaNumber', async (req, res) => { })); await saveRoundHistoryToDB(pdgaNumber, roundsForDB, false); - console.log(`✓ Saved ${allRounds.length} rounds using optimized approach`); + logger.info(`✓ Saved ${allRounds.length} rounds using optimized approach`); await updateLastRoundUpdateDate(pdgaNumber); } else { - console.log('ℹ No rounds found'); + logger.info('ℹ No rounds found'); } } catch (detailsError) { - console.error('Failed to fetch rounds using optimized approach:', detailsError.message); + logger.error('Failed to fetch rounds using optimized approach:', detailsError.message); allRounds = []; } @@ -460,15 +461,15 @@ router.post('/api/refresh-round-history/:pdgaNumber', async (req, res) => { message: `Used /details (${officialCount} rounds) + new tournaments (${newCount} rounds)` }); } catch (error) { - console.error(`=== Error refreshing round history for PDGA ${pdgaNumber} ===`); - console.error('Error type:', error.constructor.name); - console.error('Error message:', error.message); + logger.error(`=== Error refreshing round history for PDGA ${pdgaNumber} ===`); + logger.error('Error type:', error.constructor.name); + logger.error('Error message:', error.message); if (browser) { try { await browser.close(); } catch (closeError) { - console.error('Error closing browser:', closeError.message); + logger.error('Error closing browser:', closeError.message); } } diff --git a/src/scrapers/course-puppeteer.js b/src/scrapers/course-puppeteer.js index 04240f9..dcdbe60 100644 --- a/src/scrapers/course-puppeteer.js +++ b/src/scrapers/course-puppeteer.js @@ -1,4 +1,5 @@ const { saveCourseToDB, saveLayoutToDB } = require('../models/course'); +const logger = require('../logger'); // In-memory cache for layout-division-event mapping const layoutEventCache = new Map(); @@ -8,7 +9,7 @@ function getLayoutEventCache() { } async function scrapeCourseDirectory(browser) { - console.log('=== Scraping Swedish courses from PDGA course directory ==='); + logger.info('Scraping Swedish courses from PDGA course directory'); const page = await browser.newPage(); const allCourses = []; let pageNumber = 0; @@ -18,7 +19,7 @@ async function scrapeCourseDirectory(browser) { while (hasMorePages) { const url = `https://www.pdga.com/course-directory/advanced?title=&field_course_location_country=SE&field_course_location_locality=&field_course_location_administrative_area=All&field_course_location_postal_code=&field_course_type_value=All&rating_value=All&field_course_holes_value=18-100&field_course_total_length_value=All&field_course_target_type_value=All&field_course_tee_type_value=All&field_location_type_value=All&field_course_camping_value=All&field_course_facilities_value=All&field_course_fees_value=All&field_course_handicap_value=All&field_course_private_value=All&field_course_signage_value=All&field_cart_friendly_value=All&page=${pageNumber}`; - console.log(`Scraping page ${pageNumber}...`); + logger.info(`Scraping page ${pageNumber}...`); await page.goto(url, { waitUntil: 'networkidle2', timeout: 45000 }); await page.waitForTimeout(1000); @@ -46,34 +47,34 @@ async function scrapeCourseDirectory(browser) { }); if (courses.length === 0) { - console.log(`No courses found on page ${pageNumber}, stopping pagination`); + logger.info(`No courses found on page ${pageNumber}, stopping pagination`); hasMorePages = false; } else { - console.log(`Found ${courses.length} courses on page ${pageNumber}`); + logger.info(`Found ${courses.length} courses on page ${pageNumber}`); allCourses.push(...courses); for (const course of courses) { try { await saveCourseToDB(course); - console.log(`✓ Saved course: ${course.name} (${course.city})`); + logger.info(`Saved course: ${course.name} (${course.city})`); } catch (err) { - console.error(`Error saving course ${course.name}:`, err.message); + logger.error(`Error saving course ${course.name}: ${err.message}`); } } pageNumber++; if (hasMorePages) { - console.log('Waiting 2s before next page...'); + logger.info('Waiting 2s before next page...'); await new Promise(resolve => setTimeout(resolve, 2000)); } } } - console.log(`✓ Total courses scraped: ${allCourses.length} across ${pageNumber} pages`); + logger.info(`Total courses scraped: ${allCourses.length} across ${pageNumber} pages`); } catch (error) { - console.error('Error scraping course directory:', error.message); + logger.error('Error scraping course directory: ' + error.message); } finally { await page.close(); } @@ -82,7 +83,7 @@ async function scrapeCourseDirectory(browser) { } async function scrapeCourseLayouts(browser, courseLink, courseId) { - console.log(`\n=== Scraping layouts from: ${courseLink} ===`); + logger.info(`Scraping layouts from: ${courseLink}`); const page = await browser.newPage(); const layouts = []; @@ -114,10 +115,10 @@ async function scrapeCourseLayouts(browser, courseLink, courseId) { }); if (layoutsTabClicked) { - console.log('✓ Layouts tab found and clicked'); + logger.info('Layouts tab found and clicked'); await page.waitForTimeout(3000); } else { - console.warn('⚠ī¸ Layouts tab not found - may be on a single-layout course page'); + logger.warn('Layouts tab not found - may be on a single-layout course page'); } const extractedLayouts = await page.evaluate(() => { @@ -198,7 +199,7 @@ async function scrapeCourseLayouts(browser, courseLink, courseId) { const courseIdInt = typeof courseId === 'string' ? parseInt(courseId) : courseId; layoutEventCache.set(courseIdInt, layouts); - console.log(`✓ Successfully parsed ${layouts.length} layouts from course page`); + logger.info(`Successfully parsed ${layouts.length} layouts from course page`); const uniqueLayouts = []; const seen = new Set(); @@ -212,20 +213,20 @@ async function scrapeCourseLayouts(browser, courseLink, courseId) { } if (uniqueLayouts.length < layouts.length) { - console.log(`ℹī¸ Deduplicated to ${uniqueLayouts.length} unique layouts`); + logger.info(`Deduplicated to ${uniqueLayouts.length} unique layouts`); } for (const layout of uniqueLayouts) { try { await saveLayoutToDB(courseId, layout); - console.log(` ✓ Saved layout: ${layout.name} (Par ${layout.par})`); + logger.info(`Saved layout: ${layout.name} (Par ${layout.par})`); } catch (err) { - console.error(` ✗ Error saving layout ${layout.name}:`, err.message); + logger.error(`Error saving layout ${layout.name}: ${err.message}`); } } } catch (error) { - console.error('Error scraping course layouts:', error.message); + logger.error('Error scraping course layouts: ' + error.message); } finally { await page.close(); } @@ -332,7 +333,7 @@ async function scrapeEventResults(browser, eventUrl, layoutsWithDivisions) { } } catch (error) { - console.error('Error scraping event results:', error.message); + logger.error('Error scraping event results: ' + error.message); } finally { await page.close(); } diff --git a/src/scrapers/player-http.js b/src/scrapers/player-http.js index 2d6f2be..46dc3ef 100644 --- a/src/scrapers/player-http.js +++ b/src/scrapers/player-http.js @@ -1,4 +1,5 @@ const https = require('https'); +const logger = require('../logger'); async function fetchPlayerDataHTTP(pdgaNumber) { return new Promise((resolve, reject) => { @@ -28,21 +29,14 @@ async function fetchPlayerDataHTTP(pdgaNumber) { headers: res.headers }; - console.log(`PDGA Response Status for #${pdgaNumber}: ${res.statusCode}`); - console.log('Response Headers:', JSON.stringify(res.headers, null, 2)); + logger.info(`PDGA Response Status for #${pdgaNumber}: ${res.statusCode}`); - if (res.headers['retry-after']) { - console.log(`Retry-After header: ${res.headers['retry-after']}`); - } - if (res.headers['x-ratelimit-limit']) { - console.log(`Rate Limit: ${res.headers['x-ratelimit-limit']}`); - } - if (res.headers['x-ratelimit-remaining']) { - console.log(`Rate Limit Remaining: ${res.headers['x-ratelimit-remaining']}`); - } - if (res.headers['x-ratelimit-reset']) { - console.log(`Rate Limit Reset: ${res.headers['x-ratelimit-reset']}`); - } + logger.debug({ + retryAfter: res.headers['retry-after'], + rateLimit: res.headers['x-ratelimit-limit'], + rateLimitRemaining: res.headers['x-ratelimit-remaining'], + rateLimitReset: res.headers['x-ratelimit-reset'] + }, `Rate limit details for #${pdgaNumber}`); const error = new Error(`HTTP ${res.statusCode}`); error.rateLimitInfo = rateLimitInfo; @@ -52,10 +46,7 @@ async function fetchPlayerDataHTTP(pdgaNumber) { }); req.on('error', (error) => { - console.log(`Request error for PDGA #${pdgaNumber}:`, error.code, error.message); - if (error.code === 'ECONNRESET') { - console.log('Connection reset - likely rate limited by PDGA'); - } + logger.error(`Request error for PDGA #${pdgaNumber}: ${error.code} ${error.message}`); reject(error); }); @@ -88,7 +79,7 @@ function parsePlayerData(html, pdgaNumber) { predictedRating: null }; } catch (error) { - console.error(`Error parsing data for PDGA ${pdgaNumber}:`, error.message); + logger.error(`Error parsing data for PDGA ${pdgaNumber}: ${error.message}`); return { pdgaNumber, name: 'Error', @@ -112,7 +103,7 @@ async function fetchRatingHistory(pdgaNumber) { timeout: 30000 }; - console.log(`Fetching rating history for PDGA #${pdgaNumber} from: https://www.pdga.com/player/${pdgaNumber}/history`); + logger.info(`Fetching rating history for PDGA #${pdgaNumber} from: https://www.pdga.com/player/${pdgaNumber}/history`); const req = https.request(options, (res) => { let data = ''; @@ -122,25 +113,20 @@ async function fetchRatingHistory(pdgaNumber) { res.on('end', () => { if (res.statusCode === 200) { - console.log(`Rating history request successful for PDGA #${pdgaNumber}`); + logger.info(`Rating history request successful for PDGA #${pdgaNumber}`); resolve(data); } else { - console.log(`Rating History Error for PDGA #${pdgaNumber}:`); - console.log(`Status: ${res.statusCode}`); - console.log('Response Headers:', JSON.stringify(res.headers, null, 2)); + logger.error(`Rating History Error for PDGA #${pdgaNumber}:`); + logger.error(`Status: ${res.statusCode}`); - if (res.headers['retry-after']) { - console.log(`Retry-After: ${res.headers['retry-after']} seconds`); - } - if (res.headers['x-ratelimit-limit']) { - console.log(`Rate Limit: ${res.headers['x-ratelimit-limit']}`); - } - if (res.headers['x-ratelimit-remaining']) { - console.log(`Rate Limit Remaining: ${res.headers['x-ratelimit-remaining']}`); - } + logger.debug({ + retryAfter: res.headers['retry-after'], + rateLimit: res.headers['x-ratelimit-limit'], + rateLimitRemaining: res.headers['x-ratelimit-remaining'] + }, `Rate limit details for history #${pdgaNumber}`); if (data.length > 0) { - console.log(`Partial response received (${data.length} bytes):`, data.substring(0, 200)); + logger.debug(`Partial response received (${data.length} bytes): ${data.substring(0, 200)}`); } const error = new Error(`HTTP ${res.statusCode} for rating history`); @@ -152,28 +138,28 @@ async function fetchRatingHistory(pdgaNumber) { }); req.on('error', (error) => { - console.log(`Rating history request error for PDGA #${pdgaNumber}:`, { + logger.error({ code: error.code, message: error.message, errno: error.errno, syscall: error.syscall - }); + }, `Rating history request error for PDGA #${pdgaNumber}`); if (error.code === 'ECONNRESET') { - console.log('Connection reset on rating history - likely rate limited by PDGA'); + logger.debug('Connection reset on rating history - likely rate limited by PDGA'); } if (error.code === 'ECONNREFUSED') { - console.log('Connection refused - PDGA server may be blocking requests'); + logger.debug('Connection refused - PDGA server may be blocking requests'); } if (error.code === 'ETIMEDOUT') { - console.log('Request timed out - server may be overloaded'); + logger.debug('Request timed out - server may be overloaded'); } reject(error); }); req.on('timeout', () => { - console.log(`Rating history request timeout for PDGA #${pdgaNumber} after 30s`); + logger.info(`Rating history request timeout for PDGA #${pdgaNumber} after 30s`); req.destroy(); reject(new Error('Request timeout')); }); diff --git a/src/scrapers/player-puppeteer.js b/src/scrapers/player-puppeteer.js index 6ae6bec..39ce289 100644 --- a/src/scrapers/player-puppeteer.js +++ b/src/scrapers/player-puppeteer.js @@ -1,4 +1,5 @@ const { parseDate } = require('../services/rating-calculator'); +const logger = require('../logger'); async function getOfficialRatingHistory(browser, pdgaNumber) { const page = await browser.newPage(); @@ -47,7 +48,7 @@ async function getOfficialRatingHistory(browser, pdgaNumber) { }); } catch (error) { - console.error('Error fetching official rating history:', error.message); + logger.error('Error fetching official rating history: ' + error.message); } finally { await page.close(); } @@ -123,7 +124,7 @@ async function getPlayerTournamentDetails(browser, pdgaNumber) { } } } catch (e) { - console.log(`Date parsing failed for "${round.dateText}": ${e.message}`); + logger.info(`Date parsing failed for "${round.dateText}": ${e.message}`); } } return { @@ -137,7 +138,7 @@ async function getPlayerTournamentDetails(browser, pdgaNumber) { tournamentRounds = fixedRounds; } catch (error) { - console.error('Error fetching tournament details:', error.message); + logger.error('Error fetching tournament details: ' + error.message); } finally { await page.close(); } @@ -153,7 +154,7 @@ async function getNewTournamentRounds(browser, pdgaNumber, afterDate) { const url = `https://www.pdga.com/player/${pdgaNumber}`; await page.goto(url, { waitUntil: 'networkidle2' }); - console.log(`Looking for tournaments after ${afterDate.toDateString()}...`); + logger.info(`Looking for tournaments after ${afterDate.toDateString()}...`); const newTournamentUrls = await page.evaluate((afterTimestamp) => { const afterDate = new Date(afterTimestamp); @@ -192,11 +193,11 @@ async function getNewTournamentRounds(browser, pdgaNumber, afterDate) { return urls; }, afterDate.getTime()); - console.log(`Found ${newTournamentUrls.length} new tournaments after ${afterDate.toDateString()}`); + logger.info(`Found ${newTournamentUrls.length} new tournaments after ${afterDate.toDateString()}`); for (const tournamentData of newTournamentUrls) { try { - console.log(`Scraping new tournament: ${tournamentData.name} (${tournamentData.date})`); + logger.info(`Scraping new tournament: ${tournamentData.name} (${tournamentData.date})`); await page.goto(tournamentData.url, { waitUntil: 'domcontentloaded', timeout: 30000 }); await page.waitForTimeout(500); @@ -238,16 +239,16 @@ async function getNewTournamentRounds(browser, pdgaNumber, afterDate) { }); }); - console.log(`✓ Found ${roundRatings.length} round ratings for ${tournamentData.name}`); + logger.info(`Found ${roundRatings.length} round ratings for ${tournamentData.name}`); } } catch (error) { - console.error(`Error scraping tournament ${tournamentData.name}:`, error.message); + logger.error(`Error scraping tournament ${tournamentData.name}: ${error.message}`); } } } catch (error) { - console.error(`Error getting new tournament rounds for PDGA ${pdgaNumber}:`, error); + logger.error(`Error getting new tournament rounds for PDGA ${pdgaNumber}: ${error.message}`); } finally { await page.close(); } @@ -256,30 +257,30 @@ async function getNewTournamentRounds(browser, pdgaNumber, afterDate) { } async function getOptimizedPlayerRounds(browser, pdgaNumber) { - console.log(`=== Optimized Round Collection for PDGA ${pdgaNumber} ===`); + logger.info(`Optimized Round Collection for PDGA ${pdgaNumber}`); try { - console.log('Step 1: Getting official rating rounds from /details page...'); + logger.info('Getting official rating rounds from /details page...'); const officialRounds = await getPlayerTournamentDetails(browser, pdgaNumber); if (officialRounds.length === 0) { - console.log('No official rounds found in details page'); + logger.info('No official rounds found in details page'); return []; } - console.log(`✓ Found ${officialRounds.length} official rating rounds`); + logger.info(`Found ${officialRounds.length} official rating rounds`); const sortedRounds = officialRounds.sort((a, b) => b.date - a.date); const latestOfficialDate = sortedRounds[0].date; - console.log(`Latest official round: ${latestOfficialDate.toDateString()}`); + logger.info(`Latest official round: ${latestOfficialDate.toDateString()}`); - console.log('Step 2: Looking for NEW tournaments since latest official round...'); + logger.info('Looking for new tournaments since latest official round...'); const newRounds = await getNewTournamentRounds(browser, pdgaNumber, latestOfficialDate); if (newRounds.length > 0) { - console.log(`✓ Found ${newRounds.length} new round ratings`); + logger.info(`Found ${newRounds.length} new round ratings`); } else { - console.log('ℹ No new tournaments found since latest official round'); + logger.info('No new tournaments found since latest official round'); } const allRounds = [ @@ -299,12 +300,12 @@ async function getOptimizedPlayerRounds(browser, pdgaNumber) { allRounds.sort((a, b) => a.date - b.date); - console.log(`=== Summary: ${officialRounds.length} official + ${newRounds.length} new = ${allRounds.length} total rounds ===`); + logger.info(`Summary: ${officialRounds.length} official + ${newRounds.length} new = ${allRounds.length} total rounds`); return allRounds; } catch (error) { - console.error('Error in optimized round collection:', error.message); + logger.error('Error in optimized round collection: ' + error.message); return []; } } diff --git a/src/services/player-service.js b/src/services/player-service.js index 4a62188..79f7157 100644 --- a/src/services/player-service.js +++ b/src/services/player-service.js @@ -2,12 +2,13 @@ const { db } = require('../db'); const { getPlayerFromDB, getRoundHistoryFromDB, savePredictedRatingToDB, savePlayerToDB } = require('../models/player'); const { fetchPlayerDataHTTP, parsePlayerData } = require('../scrapers/player-http'); const { calculatePredictedRating } = require('./rating-calculator'); +const logger = require('../logger'); async function getPlayerDataFromDB(pdgaNumber) { try { const cachedPlayer = await getPlayerFromDB(pdgaNumber); if (cachedPlayer) { - console.log(`Loading PDGA ${pdgaNumber} from DB (source of truth)`); + logger.debug(`Loading PDGA ${pdgaNumber} from DB (source of truth)`); let predictedRating = cachedPlayer.predicted_rating; let stdDev = cachedPlayer.std_dev; @@ -28,33 +29,33 @@ async function getPlayerDataFromDB(pdgaNumber) { } return null; } catch (err) { - console.error(`Database error for PDGA ${pdgaNumber}:`, err.message); + logger.error(`Database error for PDGA ${pdgaNumber}:`, err.message); return null; } } async function scrapePDGARating(pdgaNumber, retries = 3) { - console.log(`=== Refreshing PDGA ${pdgaNumber} from PDGA website ===`); + logger.info(`Refreshing PDGA ${pdgaNumber} from PDGA website`); for (let attempt = 1; attempt <= retries; attempt++) { try { - console.log(`Attempt ${attempt}/${retries} for PDGA ${pdgaNumber} (using HTTP)`); + logger.info(`Attempt ${attempt}/${retries} for PDGA ${pdgaNumber} (using HTTP)`); const html = await fetchPlayerDataHTTP(pdgaNumber); const result = parsePlayerData(html, pdgaNumber); try { await savePlayerToDB(result); - console.log(`Saved PDGA ${pdgaNumber} to database`); + logger.info(`Saved PDGA ${pdgaNumber} to database`); } catch (dbErr) { - console.error(`Failed to save PDGA ${pdgaNumber} to database:`, dbErr.message); + logger.error(`Failed to save PDGA ${pdgaNumber} to database:`, dbErr.message); } - console.log(`Successfully scraped PDGA ${pdgaNumber} on attempt ${attempt}`); + logger.info(`Successfully scraped PDGA ${pdgaNumber} on attempt ${attempt}`); return result; } catch (error) { - console.error(`Attempt ${attempt}/${retries} failed for PDGA ${pdgaNumber}:`, error.message); + logger.error(`Attempt ${attempt}/${retries} failed for PDGA ${pdgaNumber}:`, error.message); if (attempt === retries) { return { @@ -72,13 +73,13 @@ async function scrapePDGARating(pdgaNumber, retries = 3) { const retryAfter = error.rateLimitInfo.headers['retry-after']; if (retryAfter) { retryDelay = Math.max(retryDelay, (parseInt(retryAfter) + 1) * 1000); - console.log(`Using Retry-After header: waiting ${retryDelay/1000}s`); + logger.warn(`Using Retry-After header: waiting ${retryDelay/1000}s`); } } if (error.code === 'ECONNRESET') { retryDelay = Math.max(retryDelay, 10000); - console.log(`Connection reset detected: waiting ${retryDelay/1000}s`); + logger.warn(`Connection reset detected: waiting ${retryDelay/1000}s`); } await new Promise(resolve => setTimeout(resolve, retryDelay)); @@ -90,7 +91,7 @@ async function getPredictedRatingFromDB(pdgaNumber) { try { const roundHistory = await getRoundHistoryFromDB(pdgaNumber); if (roundHistory.length > 0) { - console.log(`Using ${roundHistory.length} cached rounds for PDGA ${pdgaNumber} prediction`); + logger.debug(`Using ${roundHistory.length} cached rounds for PDGA ${pdgaNumber} prediction`); const roundRatings = roundHistory.map(round => ({ rating: round.rating, @@ -106,7 +107,7 @@ async function getPredictedRatingFromDB(pdgaNumber) { } return 0; } catch (err) { - console.error(`Error getting predicted rating from DB for ${pdgaNumber}:`, err.message); + logger.error(`Error getting predicted rating from DB for ${pdgaNumber}:`, err.message); return 0; } } @@ -124,7 +125,7 @@ async function getAllRatingsFromDB(progressCallback = null) { ); }); - console.log(`Loading ${allPlayers.length} players from database...`); + logger.info(`Loading ${allPlayers.length} players from database...`); const ratings = []; const total = allPlayers.length; @@ -159,7 +160,7 @@ async function getAllRatingsFromDB(progressCallback = null) { }); } } catch (error) { - console.error(`Failed to load PDGA ${pdgaNumber} from database:`, error.message); + logger.error(`Failed to load PDGA ${pdgaNumber} from database:`, error.message); const errorData = { pdgaNumber: parseInt(pdgaNumber), name: player.name || 'Database Error', @@ -183,7 +184,7 @@ async function getAllRatingsFromDB(progressCallback = null) { return ratings.sort((a, b) => (b.rating || 0) - (a.rating || 0)); } catch (error) { - console.error('Error loading players from database:', error); + logger.error('Error loading players from database:', error); return []; } } @@ -201,7 +202,7 @@ async function refreshAllPlayersInDB(progressCallback = null) { ); }); - console.log(`Refreshing ${allPlayers.length} players from database...`); + logger.info(`Refreshing ${allPlayers.length} players from database...`); const ratings = []; const total = allPlayers.length; @@ -210,7 +211,7 @@ async function refreshAllPlayersInDB(progressCallback = null) { const player = allPlayers[i]; const pdgaNumber = player.pdga_number; - console.log(`Refreshing PDGA ${pdgaNumber}... (${i + 1}/${total})`); + logger.info(`Refreshing PDGA ${pdgaNumber}... (${i + 1}/${total})`); if (progressCallback) { progressCallback({ @@ -237,7 +238,7 @@ async function refreshAllPlayersInDB(progressCallback = null) { await new Promise(resolve => setTimeout(resolve, 2000)); } catch (error) { - console.error(`Failed to refresh PDGA ${pdgaNumber}:`, error.message); + logger.error(`Failed to refresh PDGA ${pdgaNumber}:`, error.message); const errorData = { pdgaNumber: parseInt(pdgaNumber), name: player.name || 'Error', @@ -261,7 +262,7 @@ async function refreshAllPlayersInDB(progressCallback = null) { return ratings.sort((a, b) => (b.rating || 0) - (a.rating || 0)); } catch (error) { - console.error('Error refreshing all players:', error); + logger.error('Error refreshing all players:', error); return []; } }