Skip to content

Commit

Permalink
Improve logging
Browse files Browse the repository at this point in the history
  • Loading branch information
elie222 committed Dec 30, 2024
1 parent 64cb6e8 commit e67ae97
Show file tree
Hide file tree
Showing 12 changed files with 228 additions and 142 deletions.
13 changes: 10 additions & 3 deletions apps/web/app/api/ai/cold-email/controller.ts
Original file line number Diff line number Diff line change
Expand Up @@ -49,14 +49,20 @@ export async function isColdEmail({
});

if (coldEmail) {
logger.info(`Already marked as cold email. ${email.from}`);
logger.info("Already marked as cold email", {
from: email.from,
userId: user.id,
});
return { isColdEmail: true, reason: "ai-already-labeled" };
}

// otherwise run through ai to see if it's a cold email
const res = await aiIsColdEmail(email, user);

logger.info(`AI is cold email: ${res.coldEmail}`);
logger.info("AI is cold email?", {
coldEmail: res.coldEmail,
userId: user.id,
});

return {
isColdEmail: !!res.coldEmail,
Expand Down Expand Up @@ -157,7 +163,8 @@ async function blockColdEmail(options: {
gmail,
key: "cold_email",
});
if (!coldEmailLabel?.id) logger.error("No gmail label id");
if (!coldEmailLabel?.id)
logger.error("No gmail label id", { userId: user.id });

const shouldArchive =
user.coldEmailBlocker === ColdEmailSetting.ARCHIVE_AND_LABEL;
Expand Down
98 changes: 62 additions & 36 deletions apps/web/app/api/google/webhook/process-history.ts
Original file line number Diff line number Diff line change
Expand Up @@ -74,7 +74,7 @@ export async function processHistoryForUser(
});

if (!account) {
logger.error(`Account not found. email: ${email}`);
logger.error("Account not found", { email });
return NextResponse.json({ ok: true });
}

Expand All @@ -83,7 +83,7 @@ export async function processHistoryForUser(
: undefined;

if (!premium) {
logger.info(`Account not premium. email: ${email}`);
logger.info("Account not premium", { email });
await unwatchEmails(account);
return NextResponse.json({ ok: true });
}
Expand All @@ -98,7 +98,7 @@ export async function processHistoryForUser(
);

if (!userHasAiAccess && !userHasColdEmailAccess) {
console.debug(`does not have hasAiOrColdEmailAccess. email: ${email}`);
logger.trace("Does not have hasAiOrColdEmailAccess", { email });
await unwatchEmails(account);
return NextResponse.json({ ok: true });
}
Expand All @@ -108,22 +108,18 @@ export async function processHistoryForUser(
account.user.coldEmailBlocker &&
account.user.coldEmailBlocker !== ColdEmailSetting.DISABLED;
if (!hasAutomationRules && !shouldBlockColdEmails) {
console.debug(
`has no rules set and cold email blocker disabled. email: ${email}`,
);
logger.trace("Has no rules set and cold email blocker disabled", { email });
return NextResponse.json({ ok: true });
}

if (!account.access_token || !account.refresh_token) {
logger.error(
`Missing access or refresh token. User needs to re-authenticate. email: ${email}`,
);
logger.error("Missing access or refresh token", { email });
return NextResponse.json({ ok: true });
}

if (!account.user.email) {
// shouldn't ever happen
logger.error(`Missing user email: ${email}`);
logger.error("Missing user email", { email });
return NextResponse.json({ ok: true });
}

Expand All @@ -147,9 +143,12 @@ export async function processHistoryForUser(
historyId - 500, // avoid going too far back
).toString();

logger.info(
`Listing history... Start: ${startHistoryId} lastSyncedHistoryId: ${account.user.lastSyncedHistoryId} gmailHistoryId: ${startHistoryId} email: ${email}`,
);
logger.info("Listing history", {
startHistoryId,
lastSyncedHistoryId: account.user.lastSyncedHistoryId,
gmailHistoryId: startHistoryId,
email,
});

const history = await gmail.users.history.list({
userId: "me",
Expand All @@ -162,9 +161,11 @@ export async function processHistoryForUser(
});

if (history.data.history) {
logger.info(
`Processing... email: ${email} startHistoryId: ${startHistoryId} historyId: ${history.data.historyId}`,
);
logger.info("Processing history", {
email,
startHistoryId,
historyId: history.data.historyId,
});

await processHistory({
history: history.data.history,
Expand All @@ -188,9 +189,10 @@ export async function processHistoryForUser(
},
});
} else {
logger.info(
`No history. startHistoryId: ${startHistoryId}. ${JSON.stringify(decodedData)}`,
);
logger.info("No history", {
startHistoryId,
decodedData,
});

// important to save this or we can get into a loop with never receiving history
await prisma.user.update({
Expand All @@ -199,7 +201,7 @@ export async function processHistoryForUser(
});
}

logger.info(`Completed. ${JSON.stringify(decodedData)}`);
logger.info("Completed processing history", { decodedData });

return NextResponse.json({ ok: true });
} catch (error) {
Expand Down Expand Up @@ -305,15 +307,19 @@ async function processHistoryItem(
});

if (!isFree) {
logger.info(
`Skipping. Message already being processed. email: ${user.email} messageId: ${messageId}`,
);
logger.info("Skipping. Message already being processed.", {
email: user.email,
messageId,
threadId,
});
return;
}

logger.info(
`Getting message... email: ${user.email} messageId: ${messageId} threadId: ${threadId}`,
);
logger.info("Getting message", {
email: user.email,
messageId,
threadId,
});

try {
const [gmailMessage, hasExistingRule] = await Promise.all([
Expand All @@ -328,7 +334,11 @@ async function processHistoryItem(

// if the rule has already been executed, skip
if (hasExistingRule) {
logger.info("Skipping. Rule already exists.");
logger.info("Skipping. Rule already exists.", {
email: user.email,
messageId,
threadId,
});
return;
}

Expand All @@ -342,9 +352,11 @@ async function processHistoryItem(
});

if (blocked) {
logger.info(
`Skipping. Blocked unsubscribed email. email: ${user.email} messageId: ${messageId} threadId: ${threadId}`,
);
logger.info("Skipping. Blocked unsubscribed email.", {
email: user.email,
messageId,
threadId,
});
return;
}

Expand All @@ -357,7 +369,11 @@ async function processHistoryItem(
);

if (shouldRunBlocker) {
logger.info("Running cold email blocker...");
logger.info("Running cold email blocker...", {
email: user.email,
messageId,
threadId,
});

const hasPreviousEmail = await hasPreviousEmailsFromSenderOrDomain(
gmail,
Expand Down Expand Up @@ -388,7 +404,11 @@ async function processHistoryItem(
});

if (response.isColdEmail) {
logger.info("Skipping. Cold email detected.");
logger.info("Skipping. Cold email detected.", {
email: user.email,
messageId,
threadId,
});
return;
}
}
Expand All @@ -407,7 +427,11 @@ async function processHistoryItem(
}

if (hasAutomationRules && hasAiAutomationAccess) {
logger.info("Running rules...");
logger.info("Running rules...", {
email: user.email,
messageId,
threadId,
});

await runRulesOnMessage({
gmail,
Expand All @@ -420,9 +444,11 @@ async function processHistoryItem(
} catch (error: any) {
// gmail bug or snoozed email: https://stackoverflow.com/questions/65290987/gmail-api-getmessage-method-returns-404-for-message-gotten-from-listhistory-meth
if (error.message === "Requested entity was not found.") {
logger.info(
`Message not found. email: ${user.email} messageId: ${messageId} threadId: ${threadId}`,
);
logger.info("Message not found", {
email: user.email,
messageId,
threadId,
});
return;
}

Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -26,7 +26,7 @@ export async function handleBatchRequest(
return NextResponse.json({ error: handleBatchResult.error });
return NextResponse.json({ ok: true });
} catch (error) {
logger.error("handleBatchRequest", { error });
logger.error("Handle batch request error", { error });
return NextResponse.json(
{ error: "Internal server error" },
{ status: 500 },
Expand All @@ -39,7 +39,10 @@ async function handleBatchInternal(request: Request) {
const body = aiCategorizeSendersSchema.parse(json);
const { userId, senders } = body;

logger.trace(`handleBatch ${userId}: ${senders.length} senders`);
logger.trace("Handle batch request", {
userId,
senders: senders.length,
});

const userResult = await validateUserAndAiAccess(userId);
if (isActionError(userResult)) return userResult;
Expand Down
Loading

1 comment on commit e67ae97

@vercel
Copy link

@vercel vercel bot commented on e67ae97 Dec 30, 2024

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Please sign in to comment.