Merge pull request #378 from senacor/feature/improve_logging

feature - Improve logging

CHANGELOG.md

@@ -1,5 +1,9 @@
 # CHANGELOG
 
+## 2.3.0 (15.01.2024)
+- Do not add the full content of `context.bindingData` to `customDimensions` for app insights logging anymore as it contains i.e. the request body.
++ Add `AppInsightForHttpTrigger.finalizeWithConfig` which allows you to configure when the request and response body should be logged and allows you to use a body sanitizer to remove sensitive data.
+
 ## 2.2.2 (03.11.2023) 
 + Added the `context` as a parameter for the `errorResponseHandler` function to enhance error handling capabilities.
 

README.md

@@ -160,8 +160,8 @@ export default middleware(functionHandler, [], [postFunction]);
 
 ### Logging and Tracing with appInsights
 
-To enhance the logging and tracing with appInsights you can wrap your function with the appInsightWrapper. Currently, this will log the query-parameter
-and binding-context of request into the customProperties, which will make your logs more searchable.
+To enhance the logging and tracing with appInsights you can wrap your function with the appInsightWrapper. 
+Currently, this will add request parameters and workflow data into the customProperties, which will make your logs more searchable.
 
 Use the `AppInsightForHttpTrigger` for your http-functions:
 ```typescript
@@ -172,6 +172,10 @@ export default middleware([AppInsightForHttpTrigger.setup], handler, [AppInsight
 
 and the `AppInsightForNonHttpTrigger` for functions with different kinds of trigger (e.g. `activityTrigger` or `timerTrigger`).
 
+Per default the request and response bodies of http requests are only logged if the request fails. You can customize this 
+behavior by using `AppInsightForHttpTrigger.finalizeWithConfig(...)` instead of `AppInsightForHttpTrigger.finalizeAppInsight`.
+There you can also provide a function to sanitize the request and response bodies to prevent logging of sensitive data.
+
 ## Support and Contact
 
 If you encounter any issues or have questions about using this middleware, please file an issue in this repository or contact the maintainers at <[email protected]> or <[email protected]>.

package.json

@@ -1,6 +1,6 @@
 {
     "name": "@senacor/azure-function-middleware",
-    "version": "2.2.2",
+    "version": "2.3.0",
     "description": "Middleware for azure functions to handle authentication, authorization, error handling and logging",
     "main": "dist/index.js",
     "types": "dist/index.d.ts",

src/appInsights/appInsightsWrapper.ts

@@ -4,6 +4,10 @@ import { TelemetryClient } from 'applicationinsights';
 
 import { consoleLogger, createAppInsightsLogger } from './Logger';
 
+type LogBehavior = 'always' | 'on_error' | 'on_success' | 'never';
+type LogDataSanitizer = (data: unknown) => unknown;
+const noOpLogDataSanitizer: LogDataSanitizer = (data) => data;
+
 const telemetryClients: { [key: string]: TelemetryClient } = {};
 
 const isDisabled =
@@ -36,31 +40,63 @@ if (!isDisabled) {
     console.log('Started appInsights');
 }
 
-const setupAppInsight = async (context: Context): Promise<void> => {
-    if (isDisabled) {
-        context.log = consoleLogger;
-        return;
-    }
-
+const setupTelemetryClient = (context: Context, additionalProperties: object) => {
     context.log('Setting up AppInsights');
 
     const telemetryClient = new TelemetryClient();
     telemetryClient.setAutoPopulateAzureProperties(true);
     telemetryClients[context.invocationId] = telemetryClient;
     context.log = createAppInsightsLogger(telemetryClient);
 
-    // excluding headers because it contains sensible data
-    const { headers, ...includedProperties } = context.bindingData;
+    const { invocationId, sys } = context.bindingData;
 
     telemetryClient.commonProperties = {
-        ...includedProperties,
+        invocationId,
+        sys,
+        ...additionalProperties,
         ...appInsights.defaultClient.commonProperties,
     };
 
     context.log('Set up AppInsights');
 };
 
-const finalizeAppInsightForHttpTrigger = async (context: Context, req: HttpRequest): Promise<void> => {
+const setupAppInsightForHttpTrigger = async (context: Context): Promise<void> => {
+    if (isDisabled) {
+        context.log = consoleLogger;
+        return;
+    }
+
+    setupTelemetryClient(context, { params: context.req?.params });
+};
+
+const setupAppInsightForNonHttpTrigger = async (context: Context): Promise<void> => {
+    if (isDisabled) {
+        context.log = consoleLogger;
+        return;
+    }
+
+    setupTelemetryClient(context, { workflowData: context.bindingData.workflowData });
+};
+
+const shouldLog = (logBehavior: LogBehavior, isError: boolean) => {
+    switch (logBehavior) {
+        case 'always':
+            return true;
+        case 'on_error':
+            return isError;
+        case 'on_success':
+            return !isError;
+        case 'never':
+            return false;
+    }
+};
+
+const finalizeAppInsightForHttpTrigger = async (
+    context: Context,
+    req: HttpRequest,
+    logBodyBehavior: LogBehavior = 'on_error',
+    bodySanitizer: LogDataSanitizer = noOpLogDataSanitizer,
+): Promise<void> => {
     if (isDisabled) {
         return;
     }
@@ -84,10 +120,9 @@ const finalizeAppInsightForHttpTrigger = async (context: Context, req: HttpReque
         context.log.warn("context.res is empty and properly shouldn't be");
     }
 
-    const properties: { [key: string]: unknown } = {};
-
-    if (context?.res?.status >= 400) {
-        properties.body = context.req?.body ?? 'NO_REQ_BODY';
+    if (shouldLog(logBodyBehavior, context?.res?.status >= 400)) {
+        context.log('Request body:', context.req?.body ? bodySanitizer(context.req?.body) : 'NO_REQ_BODY');
+        context.log('Response body:', context.res?.body ? bodySanitizer(context.res?.body) : 'NO_RES_BODY');
     }
 
     telemetryClient.trackRequest({
@@ -98,7 +133,6 @@ const finalizeAppInsightForHttpTrigger = async (context: Context, req: HttpReque
         url: req.url,
         duration: 0,
         id: correlationContext?.operation?.id ?? 'UNDEFINED',
-        properties,
     });
 
     telemetryClient.flush();
@@ -123,8 +157,6 @@ const finalizeAppInsightForNonHttpTrigger = async (context: Context): Promise<vo
         ...telemetryClient.commonProperties,
     };
 
-    const properties: { [key: string]: unknown } = {};
-
     telemetryClient.trackRequest({
         name: context.executionContext.functionName,
         resultCode: 0,
@@ -133,21 +165,23 @@ const finalizeAppInsightForNonHttpTrigger = async (context: Context): Promise<vo
         url: '',
         duration: 0,
         id: correlationContext?.operation?.id ?? 'UNDEFINED',
-        properties,
     });
 
     telemetryClient.flush();
     delete telemetryClients[context.invocationId];
 };
 
 const AppInsightForHttpTrigger = {
-    setup: setupAppInsight,
+    setup: setupAppInsightForHttpTrigger,
     finalizeAppInsight: finalizeAppInsightForHttpTrigger,
+    finalizeWithConfig:
+        (logBodyBehavior: LogBehavior, bodySanitizer: LogDataSanitizer) => (context: Context, req: HttpRequest) =>
+            finalizeAppInsightForHttpTrigger(context, req, logBodyBehavior, bodySanitizer),
 };
 
 const AppInsightForNoNHttpTrigger = {
-    setup: setupAppInsight,
+    setup: setupAppInsightForNonHttpTrigger,
     finalizeAppInsight: finalizeAppInsightForNonHttpTrigger,
 };
 
-export { AppInsightForHttpTrigger, AppInsightForNoNHttpTrigger };
+export { AppInsightForHttpTrigger, AppInsightForNoNHttpTrigger, LogBehavior, LogDataSanitizer };