feat: log subreddit screening outcomes

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(
+            selected = post;
-              `Found eligible post in r/${subreddit.name}${prioritizeRecent ? ' (recent match)' : ''}`,
+            summary.deferred = newestFirst.length - index - 1;
-            );
+            break;
-            return [post];
           }
 
           // 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,

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',