Add more trace logging to standalone_ impls

This patch adds additional trace logging to the standalone receiver and
sender applications, in order to allow more diagnostics and performance
analysis.

Change-Id: I504f391f1a46b6bf0ac44a74bce244d8d36433aa
Reviewed-on: https://chromium-review.googlesource.com/c/openscreen/+/2433430
Reviewed-by: Ryan Keane <rwkeane@google.com>
Commit-Queue: Jordan Bayles <jophba@chromium.org>

6 files changed, 16 insertions, 3 deletions

diff --git a/cast/standalone_receiver/cast_agent.cc b/cast/standalone_receiver/cast_agent.cc
index d574d4f7..791029a3 100644
--- a/cast/standalone_receiver/cast_agent.cc
+++ b/cast/standalone_receiver/cast_agent.cc
@@ -19,6 +19,7 @@
 #include "platform/base/tls_listen_options.h"
 #include "util/json/json_serialization.h"
 #include "util/osp_logging.h"
+#include "util/trace_logging.h"
 
 namespace openscreen {
 namespace cast {
@@ -50,6 +51,7 @@ CastAgent::CastAgent(
 CastAgent::~CastAgent() = default;
 
 Error CastAgent::Start() {
+  TRACE_DEFAULT_SCOPED(TraceCategory::kStandaloneReceiver);
   OSP_CHECK(!current_session_);
 
   task_runner_->PostTask([this] {
@@ -91,6 +93,7 @@ Error CastAgent::Stop() {
 void CastAgent::OnConnected(ReceiverSocketFactory* factory,
                             const IPEndpoint& endpoint,
                             std::unique_ptr<CastSocket> socket) {
+  TRACE_DEFAULT_SCOPED(TraceCategory::kStandaloneReceiver);
   if (current_session_) {
     OSP_LOG_WARN << "Already connected, dropping peer at: " << endpoint;
     return;
diff --git a/cast/standalone_receiver/main.cc b/cast/standalone_receiver/main.cc
index ff0021f0..803b3414 100644
--- a/cast/standalone_receiver/main.cc
+++ b/cast/standalone_receiver/main.cc
@@ -55,6 +55,7 @@ ErrorOr<std::unique_ptr<DiscoveryState>> StartDiscovery(
     const InterfaceInfo& interface,
     const std::string& friendly_name,
     const std::string& model_name) {
+  TRACE_DEFAULT_SCOPED(TraceCategory::kStandaloneReceiver);
   discovery::Config config;
 
   discovery::Config::NetworkInfo::AddressFamilies supported_address_families =
@@ -99,6 +100,7 @@ ErrorOr<std::unique_ptr<DiscoveryState>> StartDiscovery(
 std::unique_ptr<CastAgent> StartCastAgent(TaskRunnerImpl* task_runner,
                                           const InterfaceInfo& interface,
                                           GeneratedCredentials* creds) {
+  TRACE_DEFAULT_SCOPED(TraceCategory::kStandaloneReceiver);
   auto agent = std::make_unique<CastAgent>(
       task_runner, interface, creds->provider.get(), creds->tls_credentials);
   const auto error = agent->Start();
diff --git a/cast/standalone_receiver/streaming_playback_controller.cc b/cast/standalone_receiver/streaming_playback_controller.cc
index b83d2cb3..3438c2ed 100644
--- a/cast/standalone_receiver/streaming_playback_controller.cc
+++ b/cast/standalone_receiver/streaming_playback_controller.cc
@@ -53,8 +53,6 @@ StreamingPlaybackController::StreamingPlaybackController(
 }
 #endif  // defined(CAST_STANDALONE_RECEIVER_HAVE_EXTERNAL_LIBS)
 
-// TODO(jophba): add async tracing to streaming implementation for exposing
-// how long the OFFER/ANSWER and receiver startup takes.
 void StreamingPlaybackController::OnNegotiated(
     const ReceiverSession* session,
     ReceiverSession::ConfiguredReceivers receivers) {
diff --git a/cast/standalone_sender/looping_file_cast_agent.cc b/cast/standalone_sender/looping_file_cast_agent.cc
index c6c9ea7c..a7e99fdb 100644
--- a/cast/standalone_sender/looping_file_cast_agent.cc
+++ b/cast/standalone_sender/looping_file_cast_agent.cc
@@ -12,6 +12,7 @@
 #include "cast/streaming/capture_recommendations.h"
 #include "cast/streaming/constants.h"
 #include "cast/streaming/offer_messages.h"
+#include "util/trace_logging.h"
 
 namespace openscreen {
 namespace cast {
@@ -39,6 +40,7 @@ LoopingFileCastAgent::LoopingFileCastAgent(TaskRunner* task_runner)
 LoopingFileCastAgent::~LoopingFileCastAgent() = default;
 
 void LoopingFileCastAgent::Connect(ConnectionSettings settings) {
+  TRACE_DEFAULT_SCOPED(TraceCategory::kStandaloneSender);
   connection_settings_ = std::move(settings);
   const auto policy = connection_settings_->should_include_video
                           ? DeviceMediaPolicy::kIncludesVideo
@@ -65,6 +67,7 @@ void LoopingFileCastAgent::Stop() {
 void LoopingFileCastAgent::OnConnected(SenderSocketFactory* factory,
                                        const IPEndpoint& endpoint,
                                        std::unique_ptr<CastSocket> socket) {
+  TRACE_DEFAULT_SCOPED(TraceCategory::kStandaloneSender);
   if (current_session_) {
     OSP_LOG_WARN << "Already connected, dropping peer at: " << endpoint;
     return;
@@ -117,6 +120,7 @@ void LoopingFileCastAgent::OnError(const SenderSession* session, Error error) {
 }
 
 void LoopingFileCastAgent::CreateAndStartSession() {
+  TRACE_DEFAULT_SCOPED(TraceCategory::kStandaloneSender);
   environment_ =
       std::make_unique<Environment>(&Clock::now, task_runner_, IPEndpoint{});
   current_session_ = std::make_unique<SenderSession>(
diff --git a/cast/standalone_sender/looping_file_sender.cc b/cast/standalone_sender/looping_file_sender.cc
index ff9bdd05..e4b795b8 100644
--- a/cast/standalone_sender/looping_file_sender.cc
+++ b/cast/standalone_sender/looping_file_sender.cc
@@ -4,6 +4,8 @@
 
 #include "cast/standalone_sender/looping_file_sender.h"
 
+#include "util/trace_logging.h"
+
 namespace openscreen {
 namespace cast {
 
@@ -85,6 +87,7 @@ void LoopingFileSender::ControlForNetworkCongestion() {
 
 void LoopingFileSender::SendFileAgain() {
   OSP_LOG_INFO << "Sending " << path_ << " (starts in one second)...";
+  TRACE_DEFAULT_SCOPED(TraceCategory::kStandaloneSender);
 
   OSP_DCHECK_EQ(num_capturers_running_, 0);
   num_capturers_running_ = 2;
@@ -103,12 +106,14 @@ void LoopingFileSender::SendFileAgain() {
 void LoopingFileSender::OnAudioData(const float* interleaved_samples,
                                     int num_samples,
                                     Clock::time_point capture_time) {
+  TRACE_DEFAULT_SCOPED(TraceCategory::kStandaloneSender);
   latest_frame_time_ = std::max(capture_time, latest_frame_time_);
   audio_encoder_.EncodeAndSend(interleaved_samples, num_samples, capture_time);
 }
 
 void LoopingFileSender::OnVideoFrame(const AVFrame& av_frame,
                                      Clock::time_point capture_time) {
+  TRACE_DEFAULT_SCOPED(TraceCategory::kStandaloneSender);
   latest_frame_time_ = std::max(capture_time, latest_frame_time_);
   StreamingVp8Encoder::VideoFrame frame{};
   frame.width = av_frame.width - av_frame.crop_left - av_frame.crop_right;
diff --git a/platform/base/trace_logging_types.h b/platform/base/trace_logging_types.h
index 64149a7e..257feaff 100644
--- a/platform/base/trace_logging_types.h
+++ b/platform/base/trace_logging_types.h
@@ -60,7 +60,8 @@ struct TraceCategory {
     kSsl = 0x01 << 2,
     kPresentation = 0x01 << 3,
     kStandaloneReceiver = 0x01 << 4,
-    kDiscovery = 0x01 << 5
+    kDiscovery = 0x01 << 5,
+    kStandaloneSender = 0x01 << 6,
   };
 };