Trace Logging: Add To Existing Code

The changes here are as follows:
- Add trace logging at the edge of our code before calling external libraries.
    This allows for us to determine if an external library is acting as
    bottlekneck for our service and to better understand our code
- Add trace logging at the start of a Read callback. This allows us to start
    tracing when a new call comes in.
- Add tracing at remaining places I'd wished we had it while debugging our demo
    code
- Update location of build variable. It previously was only being applied to the
    platform code which meant calls to the macros from outside of platform did
    not log.
- Default trace logging to off. The new logs pollute the output of the demo so,
    until a different output stream for trace logs is created, they should only
    be enabled by those that want them, rather than all users

Bug: openscreen:38
Change-Id: I47a41c00b30f7167f978926c89063fd454808a26
Reviewed-on: https://chromium-review.googlesource.com/c/openscreen/+/1733738
Commit-Queue: Ryan Keane <rwkeane@google.com>
Reviewed-by: Max Yakimakha <yakimakha@chromium.org>

1 files changed, 33 insertions, 5 deletions

diff --git a/osp/impl/presentation/presentation_receiver.cc b/osp/impl/presentation/presentation_receiver.cc
index 95888ff5..5c3cd0d1 100644
--- a/osp/impl/presentation/presentation_receiver.cc
+++ b/osp/impl/presentation/presentation_receiver.cc
@@ -14,6 +14,7 @@
 #include "osp/public/protocol_connection_server.h"
 #include "platform/api/logging.h"
 #include "platform/api/time.h"
+#include "platform/api/trace_logging.h"
 
 namespace openscreen {
 namespace presentation {
@@ -105,8 +106,11 @@ ErrorOr<size_t> Receiver::OnStreamMessage(uint64_t endpoint_id,
                                           const uint8_t* buffer,
                                           size_t buffer_size,
                                           platform::Clock::time_point now) {
+  TRACE_SCOPED(TraceCategory::Presentation, "Receiver::OnStreamMessage");
   switch (message_type) {
     case msgs::Type::kPresentationUrlAvailabilityRequest: {
+      TRACE_SCOPED(TraceCategory::Presentation,
+                   "kPresentationUrlAvailabilityRequest");
       OSP_VLOG << "got presentation-url-availability-request";
       msgs::PresentationUrlAvailabilityRequest request;
       ssize_t decode_result = msgs::DecodePresentationUrlAvailabilityRequest(
@@ -114,6 +118,7 @@ ErrorOr<size_t> Receiver::OnStreamMessage(uint64_t endpoint_id,
       if (decode_result < 0) {
         OSP_LOG_WARN << "Presentation-url-availability-request parse error: "
                      << decode_result;
+        TRACE_SET_RESULT(Error::Code::kParseError);
         return Error::Code::kParseError;
       }
 
@@ -130,6 +135,7 @@ ErrorOr<size_t> Receiver::OnStreamMessage(uint64_t endpoint_id,
     }
 
     case msgs::Type::kPresentationStartRequest: {
+      TRACE_SCOPED(TraceCategory::Presentation, "kPresentationStartRequest");
       OSP_VLOG << "got presentation-start-request";
       msgs::PresentationStartRequest request;
       const ssize_t result =
@@ -137,6 +143,7 @@ ErrorOr<size_t> Receiver::OnStreamMessage(uint64_t endpoint_id,
       if (result < 0) {
         OSP_LOG_WARN << "Presentation-initiation-request parse error: "
                      << result;
+        TRACE_SET_RESULT(Error::Code::kParseError);
         return Error::Code::kParseError;
       }
 
@@ -151,8 +158,11 @@ ErrorOr<size_t> Receiver::OnStreamMessage(uint64_t endpoint_id,
         Error write_error = WritePresentationInitiationResponse(
             response, GetProtocolConnection(endpoint_id).get());
 
-        if (!write_error.ok())
+        if (!write_error.ok()) {
+          TRACE_SET_RESULT(write_error);
           return write_error;
+        }
+
         return result;
       }
 
@@ -177,12 +187,17 @@ ErrorOr<size_t> Receiver::OnStreamMessage(uint64_t endpoint_id,
       response.result = msgs::PresentationStartResponse_result::kUnknownError;
       Error write_error = WritePresentationInitiationResponse(
           response, GetProtocolConnection(endpoint_id).get());
-      if (!write_error.ok())
+      if (!write_error.ok()) {
+        TRACE_SET_RESULT(write_error);
         return write_error;
+      }
+
       return result;
     }
 
     case msgs::Type::kPresentationConnectionOpenRequest: {
+      TRACE_SCOPED(TraceCategory::Presentation,
+                   "kPresentationConnectionOpenRequest");
       OSP_VLOG << "Got a presentation-connection-open-request";
       msgs::PresentationConnectionOpenRequest request;
       const ssize_t result = msgs::DecodePresentationConnectionOpenRequest(
@@ -190,6 +205,7 @@ ErrorOr<size_t> Receiver::OnStreamMessage(uint64_t endpoint_id,
       if (result < 0) {
         OSP_LOG_WARN << "Presentation-connection-open-request parse error: "
                      << result;
+        TRACE_SET_RESULT(Error::Code::kParseError);
         return Error::Code::kParseError;
       }
 
@@ -207,8 +223,11 @@ ErrorOr<size_t> Receiver::OnStreamMessage(uint64_t endpoint_id,
             kInvalidPresentationId;
         Error write_error = WritePresentationConnectionOpenResponse(
             response, GetProtocolConnection(endpoint_id).get());
-        if (!write_error.ok())
+        if (!write_error.ok()) {
+          TRACE_SET_RESULT(write_error);
           return write_error;
+        }
+
         return result;
       }
 
@@ -236,12 +255,17 @@ ErrorOr<size_t> Receiver::OnStreamMessage(uint64_t endpoint_id,
           msgs::PresentationConnectionOpenResponse_result::kUnknownError;
       Error write_error = WritePresentationConnectionOpenResponse(
           response, GetProtocolConnection(endpoint_id).get());
-      if (!write_error.ok())
+      if (!write_error.ok()) {
+        TRACE_SET_RESULT(write_error);
         return write_error;
+      }
+
       return result;
     }
 
     case msgs::Type::kPresentationTerminationRequest: {
+      TRACE_SCOPED(TraceCategory::Presentation,
+                   "kPresentationTerminationRequest");
       OSP_VLOG << "got presentation-termination-request";
       msgs::PresentationTerminationRequest request;
       const ssize_t result = msgs::DecodePresentationTerminationRequest(
@@ -249,6 +273,7 @@ ErrorOr<size_t> Receiver::OnStreamMessage(uint64_t endpoint_id,
       if (result < 0) {
         OSP_LOG_WARN << "Presentation-termination-request parse error: "
                      << result;
+        TRACE_SET_RESULT(Error::Code::kParseError);
         return Error::Code::kParseError;
       }
 
@@ -272,8 +297,10 @@ ErrorOr<size_t> Receiver::OnStreamMessage(uint64_t endpoint_id,
             kInvalidPresentationId;
         Error write_error = WritePresentationTerminationResponse(
             response, GetProtocolConnection(endpoint_id).get());
-        if (!write_error.ok())
+        if (!write_error.ok()) {
+          TRACE_SET_RESULT(write_error);
           return write_error;
+        }
         return result;
       }
 
@@ -289,6 +316,7 @@ ErrorOr<size_t> Receiver::OnStreamMessage(uint64_t endpoint_id,
     }
 
     default:
+      TRACE_SET_RESULT(Error::Code::kUnknownMessageType);
       return Error::Code::kUnknownMessageType;
   }
 }