diff --git a/CreateMessage/handler.ts b/CreateMessage/handler.ts index 8d5d9497..dbb03e5d 100644 --- a/CreateMessage/handler.ts +++ b/CreateMessage/handler.ts @@ -391,11 +391,9 @@ export function CreateMessageHandler( isSuccess: boolean ): void => context.log.verbose( - `CreateMessageHandler|${ - isSuccess ? "SUCCESS" : "FAILURE" - }|SERVICE_ID=${serviceId}|RECIPIENT=${fiscalCode}|RESPONSE=${r.kind}|${ - r.detail - }` + `CreateMessageHandler|SERVICE_ID=${serviceId}|RECIPIENT=${fiscalCode}|RESPONSE=${ + r.kind + }|${r.detail}|RESULT=${isSuccess ? "SUCCESS" : "FAILURE"}` ); // here we create an async Task that processes the request diff --git a/CreateNotificationActivity/handler.ts b/CreateNotificationActivity/handler.ts index a6698b07..b86b2d1e 100644 --- a/CreateNotificationActivity/handler.ts +++ b/CreateNotificationActivity/handler.ts @@ -31,14 +31,13 @@ import { ISuccessfulStoreMessageContentActivityResult } from "../StoreMessageCon * Attempt to resolve an email address from * the recipient profile. */ -function getEmailAddressFromProfile( +const getEmailAddressFromProfile = ( profile: RetrievedProfile -): Option { - return fromNullable(profile.email).map(email => ({ +): Option => + fromNullable(profile.email).map(email => ({ addressSource: NotificationAddressSourceEnum.PROFILE_ADDRESS, toAddress: email })); -} /** * Try to create (save) a new notification @@ -102,6 +101,10 @@ export const getCreateNotificationActivityHandler = ( ): Promise => { const { createdMessageEvent, storeMessageContentActivityResult } = input; + const logPrefix = `CreateNotificationActivity|MESSAGE_ID=${createdMessageEvent.message.id}|RECIPIENT=${createdMessageEvent.message.fiscalCode}`; + + context.log.verbose(`${logPrefix}|STARTING`); + const { senderMetadata, message: newMessageWithoutContent @@ -118,14 +121,15 @@ export const getCreateNotificationActivityHandler = ( const isEmailBlockedForService = blockedInboxOrChannels.indexOf(BlockedInboxOrChannelEnum.EMAIL) >= 0; + const emailFromProfile = getEmailAddressFromProfile(profile); + const maybeAllowedEmailNotification = isEmailBlockedForService ? none - : getEmailAddressFromProfile(profile).orElse(() => { - context.log.verbose( - `CreateNotificationActivity|User profile has no email address set|${profile.fiscalCode}` - ); - return none; - }); + : emailFromProfile; + + context.log.verbose( + `${logPrefix}|CHANNEL=EMAIL|SERVICE_BLOCKED=${isEmailBlockedForService}|PROFILE_EMAIL=${emailFromProfile.isSome()}|WILL_NOTIFY=${maybeAllowedEmailNotification.isSome()}` + ); // // Webhook notification @@ -136,10 +140,10 @@ export const getCreateNotificationActivityHandler = ( blockedInboxOrChannels.indexOf(BlockedInboxOrChannelEnum.WEBHOOK) >= 0; // whether the recipient wants us to send notifications to the app backend - const isWebhookBlockedInProfile = profile.isWebhookEnabled === true; + const isWebhookEnabledInProfile = profile.isWebhookEnabled === true; const isWebhookEnabled = - !isWebhookBlockedForService && isWebhookBlockedInProfile; + !isWebhookBlockedForService && isWebhookEnabledInProfile; const maybeAllowedWebhookNotification = isWebhookEnabled ? some({ @@ -147,6 +151,10 @@ export const getCreateNotificationActivityHandler = ( }) : none; + context.log.verbose( + `${logPrefix}|CHANNEL=WEBHOOK|CHANNEL_ENABLED=${isWebhookEnabledInProfile}|SERVICE_BLOCKED=${isWebhookBlockedForService}|WILL_NOTIFY=${maybeAllowedWebhookNotification.isSome()}` + ); + // store fiscalCode -> serviceId const errorOrSenderService = await lSenderServiceModel.createOrUpdate( newSenderService( @@ -159,6 +167,7 @@ export const getCreateNotificationActivityHandler = ( ); if (isLeft(errorOrSenderService)) { + context.log.error(`${logPrefix}|ERROR=${errorOrSenderService.value.body}`); throw new Error( `Cannot save sender service id: ${errorOrSenderService.value.body}` ); @@ -170,9 +179,7 @@ export const getCreateNotificationActivityHandler = ( ].every(_ => _.isNone()); if (noChannelsConfigured) { - context.log.verbose( - `CreateNotificationActivity|No channels configured for the user ${newMessageWithoutContent.fiscalCode} and no default address provided` - ); + context.log.warn(`${logPrefix}|RESULT=NO_CHANNELS_ENABLED`); // return no notifications return { kind: "none" }; } @@ -198,6 +205,8 @@ export const getCreateNotificationActivityHandler = ( newNotification ); + context.log.verbose(`${logPrefix}|RESULT=SUCCESS`); + // output notification events (one for each channel) return { hasEmail: maybeAllowedEmailNotification.isSome(), diff --git a/EmailNotificationActivity/handler.ts b/EmailNotificationActivity/handler.ts index 6ca5572a..1ca60ea2 100644 --- a/EmailNotificationActivity/handler.ts +++ b/EmailNotificationActivity/handler.ts @@ -72,6 +72,8 @@ export const getEmailNotificationActivityHandler = ( const emailNotificationEvent = decodedEmailNotification.value; + const logPrefix = `EmailNotificationActivity|MESSAGE_ID=${emailNotificationEvent.message.id}|RECIPIENT=${emailNotificationEvent.message.fiscalCode}|NOTIFICATION_ID=${emailNotificationEvent.notificationId}`; + const { message, content, @@ -102,9 +104,7 @@ export const getEmailNotificationActivityHandler = ( message.timeToLiveSeconds * 1000 ) { // if the message is expired no more processing is necessary - context.log.verbose( - `EmailNotificationActivity|Message expired|MESSAGE_ID=${message.id}` - ); + context.log.warn(`${logPrefix}|RESULT=TTL_EXPIRED`); return { kind: "SUCCESS", result: "EXPIRED" }; } @@ -116,18 +116,16 @@ export const getEmailNotificationActivityHandler = ( if (isLeft(errorOrMaybeNotification)) { const error = errorOrMaybeNotification.value; // we got an error while fetching the notification - throw new Error( - `EmailNotificationActivity|Error while fetching the notification|NOTIFICATION_ID=${notificationId}|MESSAGE_ID=${message.id}|ERROR=${error.code}` - ); + context.log.warn(`${logPrefix}|ERROR=${error.body}`); + throw new Error(`Error while fetching the notification: ${error.body}`); } const maybeEmailNotification = errorOrMaybeNotification.value; if (isNone(maybeEmailNotification)) { // it may happen that the object is not yet visible to this function due to latency // as the notification object is retrieved from database and we may be hitting a // replica that is not yet in sync - throw new Error( - `EmailNotificationActivity|Notification not found|NOTIFICATION_ID=${notificationId}|MESSAGE_ID=${message.id}` - ); + context.log.warn(`${logPrefix}|RESULT=NOTIFICATION_NOT_FOUND`); + throw new Error(`Notification not found`); } const errorOrEmailNotification = EmailNotification.decode( maybeEmailNotification.value @@ -135,9 +133,7 @@ export const getEmailNotificationActivityHandler = ( if (isLeft(errorOrEmailNotification)) { // The notification object is not compatible with this code const error = readableReport(errorOrEmailNotification.value); - context.log.error( - `EmailNotificationActivity|Wrong format for email notification|NOTIFICATION_ID=${notificationId}|MESSAGE_ID=${message.id}|ERROR=${error}` - ); + context.log.error(`${logPrefix}|ERROR=${error}`); return { kind: "FAILURE", reason: "WRONG_FORMAT" }; } const emailNotification = errorOrEmailNotification.value.channels.EMAIL; @@ -189,9 +185,7 @@ export const getEmailNotificationActivityHandler = ( resultCode: error.name, success: false }); - context.log.error( - `EmailNotificationActivity|Error while sending email|NOTIFICATION_ID=${notificationId}|MESSAGE_ID=${message.id}|ERROR=${error.message}` - ); + context.log.error(`${logPrefix}|ERROR=${error.message}`); throw new Error("Error while sending email"); } @@ -213,6 +207,8 @@ export const getEmailNotificationActivityHandler = ( } }); + context.log.verbose(`${logPrefix}|RESULT=SUCCESS`); + // TODO: handling bounces and delivery updates // see https://nodemailer.com/usage/#sending-mail // see #150597597 diff --git a/MessageStatusUpdaterActivity/handler.ts b/MessageStatusUpdaterActivity/handler.ts index 98c16d87..5ecf9927 100644 --- a/MessageStatusUpdaterActivity/handler.ts +++ b/MessageStatusUpdaterActivity/handler.ts @@ -26,7 +26,7 @@ export const getMessageStatusUpdaterActivityHandler = ( const decodedInput = Input.decode(input); if (decodedInput.isLeft()) { context.log.error( - `MessageStatusUpdaterActivity|Cannot decode input|ERROR=${ReadableReporter.report( + `MessageStatusUpdaterActivity|ERROR=${ReadableReporter.report( decodedInput ).join(" / ")}` ); @@ -44,13 +44,13 @@ export const getMessageStatusUpdaterActivityHandler = ( if (result.isLeft()) { context.log.error( - `MessageStatusUpdaterActivity|Error while updating message status|MESSAGE_ID=${messageId}|STATUS=${status}|ERROR=${result.value.message}` + `MessageStatusUpdaterActivity|MESSAGE_ID=${messageId}|STATUS=${status}|ERROR=${result.value.message}` ); throw new Error(result.value.message); } context.log.verbose( - `MessageStatusUpdaterActivity|Message status updated|MESSAGE_ID=${messageId}|STATUS=${status}` + `MessageStatusUpdaterActivity|MESSAGE_ID=${messageId}|STATUS=${status}|RESULT=SUCCESS` ); return { kind: "SUCCESS" }; diff --git a/NotificationStatusUpdaterActivity/handler.ts b/NotificationStatusUpdaterActivity/handler.ts index 60169a33..5577ffc5 100644 --- a/NotificationStatusUpdaterActivity/handler.ts +++ b/NotificationStatusUpdaterActivity/handler.ts @@ -58,13 +58,13 @@ export const getNotificationStatusUpdaterActivityHandler = ( if (errorOrUpdatedNotificationStatus.isLeft()) { context.log.warn( - `NotificationStatusUpdaterActivity|Error while updating|MESSAGE_ID=${messageId}|NOTIFICATION_ID=${notificationId}|CHANNEL=${channel}|STATUS=${status}|ERROR=${errorOrUpdatedNotificationStatus.value}` + `NotificationStatusUpdaterActivity|MESSAGE_ID=${messageId}|NOTIFICATION_ID=${notificationId}|CHANNEL=${channel}|STATUS=${status}|ERROR=${errorOrUpdatedNotificationStatus.value}` ); throw new Error(errorOrUpdatedNotificationStatus.value.message); } context.log.verbose( - `NotificationStatusUpdaterActivity|Notification status updated|MESSAGE_ID=${messageId}|NOTIFICATION_ID=${notificationId}|CHANNEL=${channel}|STATUS=${status}` + `NotificationStatusUpdaterActivity|MESSAGE_ID=${messageId}|NOTIFICATION_ID=${notificationId}|CHANNEL=${channel}|STATUS=${status}|RESULT=SUCCESS` ); return { kind: "SUCCESS" }; diff --git a/StoreMessageContentActivity/handler.ts b/StoreMessageContentActivity/handler.ts index 96129d14..0e2fc2c6 100644 --- a/StoreMessageContentActivity/handler.ts +++ b/StoreMessageContentActivity/handler.ts @@ -43,9 +43,9 @@ export const getStoreMessageContentActivityHandler = ( ): Promise => { const newMessageWithoutContent = createdMessageEvent.message; - context.log.verbose( - `StoreMessageContentActivity|Received createdMessageEvent|MESSAGE_ID=${newMessageWithoutContent.id}|RECIPIENT=${newMessageWithoutContent.fiscalCode}` - ); + const logPrefix = `StoreMessageContentActivity|MESSAGE_ID=${newMessageWithoutContent.id}|RECIPIENT=${newMessageWithoutContent.fiscalCode}`; + + context.log.verbose(`${logPrefix}|STARTING`); // fetch user's profile associated to the fiscal code // of the recipient of the message @@ -54,9 +54,10 @@ export const getStoreMessageContentActivityHandler = ( ); if (isLeft(errorOrMaybeProfile)) { - // The query has failed, we consider this as a trainsient error. + // The query has failed, we consider this as a transient error. // It's *critical* to trigger a retry here, otherwise no message // content will be saved. + context.log.error(`${logPrefix}|ERROR=${errorOrMaybeProfile.value.body}`); throw Error("Error while fetching profile"); } @@ -64,6 +65,7 @@ export const getStoreMessageContentActivityHandler = ( if (isNone(maybeProfile)) { // the recipient doesn't have any profile yet + context.log.warn(`${logPrefix}|RESULT=PROFILE_NOT_FOUND`); return { kind: "FAILURE", reason: "PROFILE_NOT_FOUND" }; } @@ -77,9 +79,7 @@ export const getStoreMessageContentActivityHandler = ( .getOrElse(new Set()); context.log.verbose( - "StoreMessageContentActivityHandler|Blocked Channels(%s): %s", - newMessageWithoutContent.fiscalCode, - JSON.stringify(blockedInboxOrChannels) + `${logPrefix}|BLOCKED_CHANNELS=${JSON.stringify(blockedInboxOrChannels)}` ); // @@ -91,6 +91,7 @@ export const getStoreMessageContentActivityHandler = ( if (!isInboxEnabled) { // the recipient's inbox is disabled + context.log.warn(`${logPrefix}|RESULT=MASTER_INBOX_DISABLED`); return { kind: "FAILURE", reason: "MASTER_INBOX_DISABLED" }; } @@ -101,6 +102,7 @@ export const getStoreMessageContentActivityHandler = ( if (isMessageStorageBlockedForService) { // the recipient's inbox is disabled + context.log.warn(`${logPrefix}|RESULT=SENDER_BLOCKED`); return { kind: "FAILURE", reason: "SENDER_BLOCKED" }; } @@ -115,6 +117,7 @@ export const getStoreMessageContentActivityHandler = ( ); if (isLeft(errorOrAttachment)) { + context.log.error(`${logPrefix}|ERROR=${errorOrAttachment.value}`); throw new Error("Error while storing message content"); } @@ -129,9 +132,12 @@ export const getStoreMessageContentActivityHandler = ( ); if (isLeft(updatedMessageOrError)) { + context.log.error(`${logPrefix}|ERROR=${updatedMessageOrError.value.body}`); throw new Error("Error while updating message pending status"); } + context.log.verbose(`${logPrefix}|RESULT=SUCCESS`); + return { // being blockedInboxOrChannels a Set, we explicitly convert it to an array // since a Set can't be serialized to JSON