diff --git a/src/services/monitor.ts b/src/services/monitor.ts index 18943b2..49cd362 100644 --- a/src/services/monitor.ts +++ b/src/services/monitor.ts @@ -4,6 +4,18 @@ import type { Config } from '../config/index.js'; import type { Logger } from '../utils/logger.js'; import { parseGenderTag } from '../utils/gender-tag.js'; +interface ListingScreeningSummary { + scanned: number; + alreadyProcessed: number; + alreadyMessaged: number; + sellerSignals: number; + missingGenderTag: number; + genderNotTargeted: number; + eligible: number; + outsideRecentWindow: number; + deferred: number; +} + export class MonitorService { // Flips on each call so that when both pools have candidates the bot // alternates between image and chat instead of always favouring whichever @@ -35,20 +47,35 @@ export class MonitorService { try { this.logger.debug(`Checking r/${subreddit.name} (${subreddit.type}) for new posts...`); const posts = await this.redditApi.getNewPosts(subreddit.name, 25, subreddit.type); + const summary: ListingScreeningSummary = { + scanned: 0, + alreadyProcessed: 0, + alreadyMessaged: 0, + sellerSignals: 0, + missingGenderTag: 0, + genderNotTargeted: 0, + eligible: 0, + outsideRecentWindow: 0, + deferred: 0, + }; + let selected: RedditPost | null = null; // Reddit normally returns /new in descending order, but sort explicitly // so we can stop as soon as the first fully eligible candidate is found. // Previously we screened the entire batch before choosing one, causing up // to two profile requests for every otherwise-valid post in the listing. const newestFirst = [...posts].sort((a, b) => b.created_utc - a.created_utc); - for (const post of newestFirst) { + for (const [index, post] of newestFirst.entries()) { + summary.scanned += 1; // Older adapters used in integrations may only expose account-local // history; production repositories provide the shared lookup. if (this.postsRepo.isProcessedAnywhere?.(post.id) ?? this.postsRepo.isProcessed(post.id)) { + summary.alreadyProcessed += 1; continue; } if (this.recipientHistory.hasSentTo(post.author)) { + summary.alreadyMessaged += 1; this.logger.debug(`Skipping post ${post.id} from u/${post.author} - already messaged this user`); continue; } @@ -64,6 +91,7 @@ export class MonitorService { post, ); if (isSeller) { + summary.sellerSignals += 1; this.logger.info(`Skipping post ${post.id} from u/${post.author} - seller signals detected`); this.recordRejection(post, subreddit.type, 'Seller signals detected'); continue; @@ -76,11 +104,13 @@ export class MonitorService { if (subreddit.type === 'chat' && targetGenders.length > 0) { const tag = parseGenderTag(`${post.title}\n${post.selftext ?? ''}`); if (!tag) { + summary.missingGenderTag += 1; this.logger.debug(`Skipping chat post ${post.id} - no gender tag in title/body`); this.recordRejection(post, subreddit.type, 'No gender tag in title/body'); continue; } if (!targetGenders.includes(tag)) { + summary.genderNotTargeted += 1; this.logger.debug( `Skipping chat post ${post.id} - gender tag "${tag}" not in target list [${targetGenders.join(', ')}]`, ); @@ -92,19 +122,29 @@ export class MonitorService { // At this point the candidate has passed every check. Select it now // rather than spending more Reddit requests screening users that // cannot be acted on during this poll cycle. + summary.eligible += 1; if (!prioritizeRecent || post.created_utc >= recentCutoffSec) { - this.logger.info( - `Found eligible post in r/${subreddit.name}${prioritizeRecent ? ' (recent match)' : ''}`, - ); - return [post]; + selected = post; + summary.deferred = newestFirst.length - index - 1; + break; } // This is the newest eligible post in this subreddit. Keep it as a // possible fallback, then move to the next subreddit to look for a // recent candidate. Older posts in this batch cannot improve it. + summary.outsideRecentWindow += 1; if (!fallback || post.created_utc > fallback.created_utc) fallback = post; + summary.deferred = newestFirst.length - index - 1; break; } + + this.logListingSummary(subreddit.name, posts.length, summary, selected !== null); + if (selected) { + this.logger.info( + `Found eligible post in r/${subreddit.name}${prioritizeRecent ? ' (recent match)' : ''}`, + ); + return [selected]; + } } catch (error) { if (error instanceof RedditRateLimitError) throw error; @@ -175,6 +215,27 @@ export class MonitorService { return new Promise((resolve) => setTimeout(resolve, ms)); } + private logListingSummary( + subreddit: string, + fetched: number, + summary: ListingScreeningSummary, + selected: boolean, + ): void { + const counts = [ + `${fetched} fetched`, + `${summary.scanned} screened`, + `${summary.alreadyProcessed} already processed`, + `${summary.alreadyMessaged} already messaged`, + `${summary.sellerSignals} seller signals`, + `${summary.missingGenderTag} missing gender tag`, + `${summary.genderNotTargeted} gender not targeted`, + `${summary.eligible} eligible${selected ? ' (selected)' : ''}`, + `${summary.outsideRecentWindow} outside recent window`, + ]; + if (summary.deferred > 0) counts.push(`${summary.deferred} not evaluated after outcome`); + this.logger.info(`r/${subreddit} listing: ${counts.join('; ')}`); + } + /** Persist a completed screening decision so later polls do not repeat it. */ private recordRejection( post: RedditPost, diff --git a/tests/monitor.test.ts b/tests/monitor.test.ts index 8969f15..64e8b6e 100644 --- a/tests/monitor.test.ts +++ b/tests/monitor.test.ts @@ -148,6 +148,30 @@ describe('MonitorService', () => { expect(postsRepo.setError).toHaveBeenCalledWith('t3_seller', 'Seller signals detected'); }); + it('logs a per-listing breakdown of screened and deferred posts', async () => { + const makePost = (id: string, author: string, created_utc: number): RedditPost => ({ + id, subreddit: 'sub1', author, title: id, + url: `http://example.com/${id}.jpg`, permalink: `/r/sub1/${id}`, thumbnail: '', + is_self: false, created_utc, over_18: true, spoiler: false, + }); + const seller = makePost('seller', 'seller', 4); + const sent = makePost('sent', 'sent', 3); + const selected = makePost('selected', 'selected', 2); + const deferred = makePost('deferred', 'deferred', 1); + const redditApi = createMockRedditApi([seller, sent, selected, deferred]); + vi.mocked(redditApi.isSellerProfile).mockImplementation(async (username) => username === 'seller'); + const config = getTestConfig({ reddit: { subreddits: [{ name: 'sub1', type: 'image' }] } }); + monitor = new MonitorService( + redditApi, createMockPostsRepo(), createMockMessagesRepo(new Set(['sent'])), config, logger, 0, + ); + + await expect(monitor.getUnprocessedPosts()).resolves.toEqual([selected]); + expect(logger.logs).toContainEqual(expect.objectContaining({ + level: 'info', + message: 'r/sub1 listing: 4 fetched; 3 screened; 0 already processed; 1 already messaged; 1 seller signals; 0 missing gender tag; 0 gender not targeted; 1 eligible (selected); 0 outside recent window; 1 not evaluated after outcome', + })); + }); + it('returns newest post when multiple valid posts exist', async () => { const post1: RedditPost = { id: 't3_1', subreddit: 'sub1', author: 'user1', title: 'Older',