Update websocket logs (#375)

* logging updates

* fix syntax

* update logs

* update logs

* update formatting

* add newline

Author: molly-moen

api-gateway-routes/api_gateway_proxy_function.rb

@@ -37,12 +37,14 @@ def on_connect(event, context)
   # connection is made.
   if authorization_error_response
     # Add some logging to make sure we know this is happening.
-    puts "AUTHORIZATION ERROR: #{authorization_error_response[:body]}"
+    puts get_formatted_log("AUTHORIZATION ERROR: #{authorization_error_response[:body]}", request_context, nil).to_json
     return { statusCode: 200, body: authorization_error_response[:body] }
   end
 
-  # Add in some logging to make debugging easier
-  puts "CONNECT REQUEST CONTEXT: #{request_context}"
+  # log entire request context object for debugging
+  request_context_log = get_formatted_log("CONNECT REQUEST CONTEXT", request_context, nil)
+  request_context_log[:request_context] = request_context
+  puts request_context_log.to_json
 
   # Return early if this is the user connectivity test
   if is_connectivity_test(authorizer)
@@ -80,7 +82,10 @@ def on_connect(event, context)
   elsif authorizer['mini_app_type'] == 'theater'
     function_name = ENV['BUILD_AND_RUN_THEATER_PROJECT_LAMBDA_ARN']
   else
-    return { statusCode: 400, body: "invalid mini-app" }
+    # log so we know we saw an invalid mini app
+    invalid_message = "invalid mini-app"
+    puts get_formatted_log(invalid_message, request_context, 400).to_json
+    return { statusCode: 400, body: invalid_message }
   end
 
   response = lambda_client.invoke({
@@ -201,7 +206,7 @@ def sqs_operation_with_retries(sqs_operation, request_context, *operation_params
     raise(e) if retries >= MAX_SQS_RETRIES
     retries += 1
     sleep(sleep_time)
-    puts "RETRY #{retries}, just slept for #{sleep_time} seconds. Request context: #{request_context}"
+    puts get_formatted_log("RETRY #{retries}, just slept for #{sleep_time} seconds", request_context, nil).to_json
     # double sleep time for next retry
     sleep_time = sleep_time * 2
     retry
@@ -229,8 +234,16 @@ def delete_queue(sqs_client, event, context)
     # This exception is expected during connectivity tests,
     # so do not log in those cases.
     unless is_connectivity_test(authorizer)
-      puts "DISCONNECT ERROR REQUEST CONTEXT: #{request_context}"
-      puts "DISCONNECT ERROR: #{e.message}"
+      puts get_formatted_log("DISCONNECT ERROR: #{e.message}", request_context, nil).to_json
     end
   end
 end
+
+def get_formatted_log(log_message, request_context, status_code)
+  log_data = {
+    connectionId: request_context['connectionId'],
+    message: log_message
+  }
+  log_data[:status_code] = status_code if status_code
+  log_data
+end

cicd/3-app/javabuilder/template.yml.erb

@@ -315,7 +315,7 @@ Resources:
       DefaultRouteSettings:
         DetailedMetricsEnabled: true
         LoggingLevel: INFO
-        DataTraceEnabled: true
+        DataTraceEnabled: false
       AccessLogSettings:
         DestinationArn: !Sub "arn:aws:logs:${AWS::Region}:${AWS::AccountId}:log-group:/aws/apigateway/accesslog/${SubDomainName}.${BaseDomainName}"
         # TODO: Also log authorizer status code, authorizer error message, Javabuilder session id, and Origin.