[Serverless] Fix flaky integration tests and make them more easily maintainable.

test/integration/serverless/log_normalize.py

@@ -0,0 +1,157 @@
+import argparse
+import json
+import re
+
+
+def normalize_metrics(stage):
+    return [
+        replace(r'raise Exception', r'\n'),
+        require(r'BEGINMETRIC.*ENDMETRIC'),
+        exclude(r'BEGINMETRIC'),
+        exclude(r'ENDMETRIC'),
+        replace(r'(ts":)[0-9]{10}', r'\1XXX'),
+        replace(r'(min":)[0-9\.e\-]{1,30}', r'\1XXX'),
+        replace(r'(max":)[0-9\.e\-]{1,30}', r'\1XXX'),
+        replace(r'(cnt":)[0-9\.e\-]{1,30}', r'\1XXX'),
+        replace(r'(avg":)[0-9\.e\-]{1,30}', r'\1XXX'),
+        replace(r'(sum":)[0-9\.e\-]{1,30}', r'\1XXX'),
+        replace(r'(k":\[)[0-9\.e\-]{1,30}', r'\1XXX'),
+        replace(r'(datadog-nodev)[0-9]+\.[0-9]+\.[0-9]+', r'\1X.X.X'),
+        replace(r'(datadog_lambda:v)[0-9]+\.[0-9]+\.[0-9]+', r'\1X.X.X'),
+        replace(r'dd_lambda_layer:datadog-go[0-9.]{1,}', r'dd_lambda_layer:datadog-gox.x.x'),
+        replace(r'(dd_lambda_layer:datadog-python)[0-9_]+\.[0-9]+\.[0-9]+', r'\1X.X.X'),
+        replace(r'(serverless.lambda-extension.integration-test.count)[0-9\.]+', r'\1'),
+        replace(r'(architecture:)(x86_64|arm64)', r'\1XXX'),
+        replace(stage, 'XXXXXX'),
+        exclude(r'[ ]$'),
+        sort_by(lambda log: (log["metric"], "cold_start:true" in log["tags"])),
+    ]
+
+
+def normalize_logs(stage):
+    return [
+        require(r'BEGINLOG.*ENDLOG'),
+        exclude(r'BEGINLOG'),
+        exclude(r'ENDLOG'),
+        replace(r'("timestamp":\s*?)\d{13}', r'\1"XXX"'),
+        replace(r'\d{4}-\d{2}-\d{2}\s\d{2}:\d{2}:\d{2}:\d{3}', 'TIMESTAMP'),
+        replace(r'\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{3}Z', 'TIMESTAMP'),
+        replace(r'\d{4}\/\d{2}\/\d{2}\s\d{2}:\d{2}:\d{2}', 'TIMESTAMP'),
+        replace(r'\d{4}-\d{2}-\d{2}\s\d{2}:\d{2}:\d{2}', 'TIMESTAMP'),
+        replace(r'([a-zA-Z0-9]{8}-[a-zA-Z0-9]{4}-[a-zA-Z0-9]{4}-[a-zA-Z0-9]{4}-[a-zA-Z0-9]{12})', r'XXX'),
+        replace(stage, 'XXXXXX'),
+        replace(r'(architecture:)(x86_64|arm64)', r'\1XXX'),
+        sort_by(lambda log: log["message"]["message"]),
+        # ignore a Lambda error that occurs sporadically for log-csharp see here for more info:
+        # https://repost.aws/questions/QUq2OfIFUNTCyCKsChfJLr5w/lambda-function-working-locally-but-crashing-on-aws
+        # TODO
+        # perl -n -e "print unless /LAMBDA_RUNTIME Failed to get next invocation. No Response from endpoint/ or \
+        #  /An error occurred while attempting to execute your code.: LambdaException/ or \
+        #  /terminate called after throwing an instance of 'std::logic_error'/ or \
+        #  /basic_string::_M_construct null not valid/" |
+    ]
+
+
+def normalize_traces(stage):
+    return [
+        require(r'BEGINTRACE.*ENDTRACE'),
+        exclude(r'BEGINTRACE'),
+        exclude(r'ENDTRACE'),
+        replace(r'(ts":)[0-9]{10}', r'\1XXX'),
+        replace(r'((startTime|endTime|traceID|trace_id|span_id|parent_id|start|system.pid)":)[0-9]+', r'\1null'),
+        replace(r'((tracer_version|language_version)":)["a-zA-Z0-9~\-\.\_]+', r'\1null'),
+        replace(r'(duration":)[0-9]+', r'\1null'),
+        replace(r'((datadog_lambda|dd_trace)":")[0-9]+\.[0-9]+\.[0-9]+', r'\1X.X.X'),
+        replace(r'(,"request_id":")[a-zA-Z0-9\-,]+"', r'\1null"'),
+        replace(r'(,"runtime-id":")[a-zA-Z0-9\-,]+"', r'\1null"'),
+        replace(r'(,"system.pid":")[a-zA-Z0-9\-,]+"', r'\1null"'),
+        replace(r'("_dd.no_p_sr":)[0-9\.]+', r'\1null'),
+        replace(r'("architecture":)"(x86_64|arm64)"', r'\1"XXX"'),
+        replace(r'("process_id":)[0-9]+', r'\1null'),
+        replace(stage, 'XXXXXX'),
+        exclude(r'[ ]$'),
+    ]
+
+
+#####################
+# BEGIN NORMALIZERS #
+#####################
+
+
+def replace(pattern, repl):
+    comp = re.compile(pattern, flags=re.DOTALL)
+
+    def _replace(log):
+        return comp.sub(repl, log)
+
+    return _replace
+
+
+def exclude(pattern):
+    return replace(pattern, '')
+
+
+def require(pattern):
+    comp = re.compile(pattern, flags=re.DOTALL)
+
+    def _require(log):
+        match = comp.search(log)
+        if not match:
+            return ''
+        return match.group(0)
+
+    return _require
+
+
+def sort_by(key):
+    def _sort(log):
+        log_json = json.loads(log, strict=False)
+        log_sorted = sorted(log_json, key=key)
+        return json.dumps(log_sorted)
+
+    return _sort
+
+
+###################
+# END NORMALIZERS #
+###################
+
+
+def normalize(log, typ, stage):
+    for normalizer in get_normalizers(typ, stage):
+        log = normalizer(log)
+    return format_json(log)
+
+
+def get_normalizers(typ, stage):
+    if typ == 'metrics':
+        return normalize_metrics(stage)
+    elif typ == 'logs':
+        return normalize_logs(stage)
+    elif typ == 'traces':
+        return normalize_traces(stage)
+    else:
+        raise ValueError(f'invalid type "{typ}"')
+
+
+def format_json(log):
+    return json.dumps(json.loads(log, strict=False), indent=2)
+
+
+def parse_args():
+    parser = argparse.ArgumentParser()
+    parser.add_argument('--type', required=True)
+    parser.add_argument('--logs', required=True)
+    parser.add_argument('--stage', required=True)
+    return parser.parse_args()
+
+
+if __name__ == '__main__':
+    try:
+        args = parse_args()
+        print(normalize(args.logs, args.type, args.stage))
+    except Exception:
+        err = {"error": "normalization raised exception"}
+        err_json = json.dumps(err, indent=2)
+        print(err_json)
+        exit(1)

test/integration/serverless/run.sh

@@ -154,20 +154,7 @@ all_functions=("${metric_functions[@]}" "${log_functions[@]}" "${trace_functions
 
 # Add a function to this list to skip checking its results
 # This should only be used temporarily while we investigate and fix the test
-functions_to_skip=(
-    # Tagging behavior after a timeout is currently known to be flaky
-    "timeout-node"
-    "timeout-python"
-    "timeout-java"
-    "timeout-go"
-    "timeout-csharp"
-    "timeout-proxy"
-    "trace-csharp" # Will be reactivated when the new dotnet layer will be released
-    "trace-proxy" # Will be reactivated when sampling with proxy will be implemented
-    "error-proxy"
-    "log-proxy"
-    "metric-proxy"
-)
+functions_to_skip=()
 
 echo "Invoking functions for the first time..."
 set +e # Don't exit this script if an invocation fails or there's a diff
@@ -215,95 +202,22 @@ for function_name in "${all_functions[@]}"; do
 
     # Replace invocation-specific data like timestamps and IDs with XXX to normalize across executions
     if [[ " ${metric_functions[*]} " =~ " ${function_name} " ]]; then
-        # Normalize metrics
-        logs=$(
-            echo "$raw_logs" |
-                perl -p -e "s/raise Exception/\n/g" |
-                grep -v "BEGINLOG.*" |
-                grep -v "BEGINTRACE.*" |
-                grep "BEGINMETRIC.*" |
-                perl -p -e "s/BEGINMETRIC/\1/g" |
-                perl -p -e "s/ENDMETRIC/\1/g" |
-                perl -p -e "s/(ts\":)[0-9]{10}/\1XXX/g" |
-                perl -p -e "s/(min\":)[0-9\.e\-]{1,30}/\1XXX/g" |
-                perl -p -e "s/(max\":)[0-9\.e\-]{1,30}/\1XXX/g" |
-                perl -p -e "s/(cnt\":)[0-9\.e\-]{1,30}/\1XXX/g" |
-                perl -p -e "s/(avg\":)[0-9\.e\-]{1,30}/\1XXX/g" |
-                perl -p -e "s/(sum\":)[0-9\.e\-]{1,30}/\1XXX/g" |
-                perl -p -e "s/(k\":\[)[0-9\.e\-]{1,30}/\1XXX/g" |
-                perl -p -e "s/(datadog-nodev)[0-9]+\.[0-9]+\.[0-9]+/\1X\.X\.X/g" |
-                perl -p -e "s/(datadog_lambda:v)[0-9]+\.[0-9]+\.[0-9]+/\1X\.X\.X/g" |
-                perl -p -e "s/dd_lambda_layer:datadog-go[0-9.]{1,}/dd_lambda_layer:datadog-gox.x.x/g" |
-                perl -p -e "s/(dd_lambda_layer:datadog-python)[0-9_]+\.[0-9]+\.[0-9]+/\1X\.X\.X/g" |
-                perl -p -e "s/(serverless.lambda-extension.integration-test.count)[0-9\.]+/\1/g" |
-                perl -p -e "s/(architecture:)(x86_64|arm64)/\1XXX/g" |
-                perl -p -e "s/$stage/XXXXXX/g" |
-                perl -p -e "s/[ ]$//g" |
-                node parse-json.js
-        )
+        norm_type=metrics
     elif [[ " ${log_functions[*]} " =~ " ${function_name} " ]]; then
-        # Normalize logs
-        logs=$(
-            echo "$raw_logs" |
-                grep "BEGINLOG" |
-                grep -v "BEGINMETRIC.*" |
-                grep -v "BEGINTRACE.*" |
-                perl -p -e "s/BEGINLOG/\1/g" |
-                perl -p -e "s/ENDLOG/\1/g" |
-                perl -p -e "s/(\"timestamp\": )\d{13}/\1\"XXX\"/g" |
-                perl -p -e "s/(\"timestamp\": )\d{13}/\1\"XXX\"/g" |
-                perl -p -e "s/\d{4}-\d{2}-\d{2}\s\d{2}:\d{2}:\d{2}:\d{3}/TIMESTAMP/g" |
-                perl -p -e "s/\d{4}-\d{2}-\d{2}T\d{2}:\d{2}:\d{2}\.\d{3}Z/TIMESTAMP/g" |
-                perl -p -e "s/\d{4}\/\d{2}\/\d{2}\s\d{2}:\d{2}:\d{2}/TIMESTAMP/g" |
-                perl -p -e "s/\d{4}-\d{2}-\d{2}\s\d{2}:\d{2}:\d{2}/TIMESTAMP/g" |
-                perl -p -e "s/\"timestamp\":\d{13},/\1/g" |
-                perl -p -e "s/([a-zA-Z0-9]{8}\-[a-zA-Z0-9]{4}\-[a-zA-Z0-9]{4}\-[a-zA-Z0-9]{4}\-[a-zA-Z0-9]{12})/\0\XXX/g" |
-                perl -p -e "s/$stage/STAGE/g" |
-                perl -p -e "s/(architecture:)(x86_64|arm64)/\1XXX/g" |
-                # ignore a Lambda error that occurs sporadically for log-csharp
-                # see here for more info: https://repost.aws/questions/QUq2OfIFUNTCyCKsChfJLr5w/lambda-function-working-locally-but-crashing-on-aws
-                perl -n -e "print unless /LAMBDA_RUNTIME Failed to get next invocation. No Response from endpoint/ or \
-                 /An error occurred while attempting to execute your code.: LambdaException/ or \
-                 /terminate called after throwing an instance of 'std::logic_error'/ or \
-                 /basic_string::_M_construct null not valid/" |
-                node parse-json.js
-        )
+        norm_type=logs
     else
-        # Normalize traces
-        logs=$(
-            echo "$raw_logs" |
-                grep "BEGINTRACE" |
-                grep -v "BEGINMETRIC.*" |
-                grep -v "BEGINLOG.*" |
-                perl -p -e "s/BEGINTRACE/\1/g" |
-                perl -p -e "s/ENDTRACE/\1/g" |
-                perl -p -e "s/(ts\":)[0-9]{10}/\1XXX/g" |
-                perl -p -e "s/((startTime|endTime|traceID|trace_id|span_id|parent_id|start|system.pid)\":)[0-9]+/\1null/g" |
-                perl -p -e "s/((tracer_version|language_version)\":)[\"a-zA-Z0-9~\-\.\_]+/\1null/g" |
-                perl -p -e "s/(duration\":)[0-9]+/\1null/g" |
-                perl -p -e "s/((datadog_lambda|dd_trace)\":\")[0-9]+\.[0-9]+\.[0-9]+/\1X\.X\.X/g" |
-                perl -p -e "s/(,\"request_id\":\")[a-zA-Z0-9\-,]+\"/\1null\"/g" |
-                perl -p -e "s/(,\"runtime-id\":\")[a-zA-Z0-9\-,]+\"/\1null\"/g" |
-                perl -p -e "s/(,\"system.pid\":\")[a-zA-Z0-9\-,]+\"/\1null\"/g" |
-                perl -p -e "s/(\"_dd.no_p_sr\":)[0-9\.]+/\1null/g" |
-                perl -p -e "s/(\"architecture\":)\"(x86_64|arm64)\"/\1\"XXX\"/g" |
-                perl -p -e "s/(\"process_id\":)[0-9]+/\1null/g" |
-                perl -p -e "s/$stage/XXXXXX/g" |
-                perl -p -e "s/[ ]$//g" |
-                node parse-json.js
-        )
+        norm_type=traces
     fi
+    logs=$(python3 log_normalize.py --type $norm_type --logs "$raw_logs" --stage $stage)
 
     function_snapshot_path="./snapshots/${function_name}"
 
-    jsonLogs="$(echo $logs | node parse-json.js)"
-
     if [ ! -f "$function_snapshot_path" ]; then
         printf "${MAGENTA} CREATE ${END_COLOR} $function_name\n"
-        echo "$jsonLogs" >"$function_snapshot_path"
+        echo "$logs" >"$function_snapshot_path"
     elif [ "$UPDATE_SNAPSHOTS" == "true" ]; then
         printf "${MAGENTA} UPDATE ${END_COLOR} $function_name\n"
-        echo "$jsonLogs" > "$function_snapshot_path"
+        echo "$logs" > "$function_snapshot_path"
     else
         if [[ " ${functions_to_skip[*]} " =~ " ${function_name} " ]]; then
             printf "${YELLOW} SKIP ${END_COLOR} $function_name\n"
@@ -314,7 +228,7 @@ for function_name in "${all_functions[@]}"; do
             printf "${YELLOW} SKIP ${END_COLOR} $function_name, no .NET support on arm64\n"
             continue
         fi
-        diff_output=$(echo "$jsonLogs" | diff - "$function_snapshot_path")
+        diff_output=$(echo "$logs" | diff - "$function_snapshot_path")
         if [ $? -eq 1 ]; then
             failed_functions+=("$function_name")