Extends WebRTC logs for software encoder fallback
This CL extends logging related to HW->SW fallbacks on the encoder
side in WebRTC. The goal is to make it easier to track down the
different steps taken when setting up the video encoder and why/when
HW encoding fails.
Current logs are added on several lines which makes regexp searching
difficult. This CL adds all related information on one line instead.
Three new search tags are also added VSE (VideoStreamEncoder), VESFW
(VideoEncoderSoftwareFallbackWrapper) and SEA (SimulcastEncoderAdapter). The idea is to allow searching for the tags to see correlated logs.
It has been verified that these added logs also show up in WebRTC
logs in Meet.
Logs from the GPU process are not included due to the sandboxed
nature which makes it much more complex to add to the native
WebRTC log. I think that these simple logs will provide value as is.
Example: https://gist.github.com/henrik-and/41946f7f0b10774241bd14d7687f770b
Bug: b/322132132
Change-Id: Iec58c9741a9dd6bab3236a88e9a6e45440f5d980
Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/339260
Commit-Queue: Henrik Andreassson <henrika@webrtc.org>
Reviewed-by: Ilya Nikolaevskiy <ilnik@webrtc.org>
Reviewed-by: Henrik Boström <hbos@webrtc.org>
Cr-Commit-Position: refs/heads/main@{#41733}
diff --git a/api/video_codecs/video_codec.cc b/api/video_codecs/video_codec.cc
index 39a345d..82c9bfc 100644
--- a/api/video_codecs/video_codec.cc
+++ b/api/video_codecs/video_codec.cc
@@ -16,6 +16,7 @@
#include "absl/strings/match.h"
#include "rtc_base/checks.h"
+#include "rtc_base/strings/string_builder.h"
namespace webrtc {
namespace {
@@ -73,6 +74,35 @@
codec_specific_(),
complexity_(VideoCodecComplexity::kComplexityNormal) {}
+std::string VideoCodec::ToString() const {
+ char string_buf[2048];
+ rtc::SimpleStringBuilder ss(string_buf);
+
+ ss << "VideoCodec {" << "type: " << CodecTypeToPayloadString(codecType)
+ << ", mode: "
+ << (mode == VideoCodecMode::kRealtimeVideo ? "RealtimeVideo"
+ : "Screensharing");
+ if (IsSinglecast()) {
+ absl::optional<ScalabilityMode> scalability_mode = GetScalabilityMode();
+ if (scalability_mode.has_value()) {
+ ss << ", Singlecast: {" << width << "x" << height << " "
+ << ScalabilityModeToString(*scalability_mode)
+ << (active ? ", active" : ", inactive") << "}";
+ }
+ } else {
+ ss << ", Simulcast: {";
+ for (size_t i = 0; i < numberOfSimulcastStreams; ++i) {
+ const SimulcastStream stream = simulcastStream[i];
+ ss << "[" << stream.width << "x" << stream.height << " "
+ << ScalabilityModeToString(stream.GetScalabilityMode())
+ << (stream.active ? ", active" : ", inactive") << "]";
+ }
+ ss << "}";
+ }
+ ss << "}";
+ return ss.str();
+}
+
VideoCodecVP8* VideoCodec::VP8() {
RTC_DCHECK_EQ(codecType, kVideoCodecVP8);
return &codec_specific_.VP8;
diff --git a/api/video_codecs/video_codec.h b/api/video_codecs/video_codec.h
index a596af1..e48ffd4 100644
--- a/api/video_codecs/video_codec.h
+++ b/api/video_codecs/video_codec.h
@@ -141,6 +141,9 @@
bool GetFrameDropEnabled() const;
void SetFrameDropEnabled(bool enabled);
+ bool IsSinglecast() const { return numberOfSimulcastStreams <= 1; }
+ bool IsSimulcast() const { return !IsSinglecast(); }
+
// Public variables. TODO(hta): Make them private with accessors.
VideoCodecType codecType;
@@ -193,6 +196,7 @@
bool operator==(const VideoCodec& other) const = delete;
bool operator!=(const VideoCodec& other) const = delete;
+ std::string ToString() const;
// Accessors for codec specific information.
// There is a const version of each that returns a reference,
diff --git a/api/video_codecs/video_encoder_software_fallback_wrapper.cc b/api/video_codecs/video_encoder_software_fallback_wrapper.cc
index d35c9f9..5f34694 100644
--- a/api/video_codecs/video_encoder_software_fallback_wrapper.cc
+++ b/api/video_codecs/video_encoder_software_fallback_wrapper.cc
@@ -264,14 +264,17 @@
}
bool VideoEncoderSoftwareFallbackWrapper::InitFallbackEncoder(bool is_forced) {
- RTC_LOG(LS_WARNING) << "Encoder falling back to software encoding.";
+ RTC_LOG(LS_WARNING) << "[VESFW] " << __func__
+ << "(is_forced=" << (is_forced ? "true" : "false") << ")";
RTC_DCHECK(encoder_settings_.has_value());
const int ret = fallback_encoder_->InitEncode(&codec_settings_,
encoder_settings_.value());
if (ret != WEBRTC_VIDEO_CODEC_OK) {
- RTC_LOG(LS_ERROR) << "Failed to initialize software-encoder fallback.";
+ RTC_LOG(LS_ERROR)
+ << "[VESFW] software-encoder fallback initialization failed with"
+ << " error code: " << WebRtcVideoCodecErrorToString(ret);
fallback_encoder_->Release();
return false;
}
@@ -305,6 +308,12 @@
int32_t VideoEncoderSoftwareFallbackWrapper::InitEncode(
const VideoCodec* codec_settings,
const VideoEncoder::Settings& settings) {
+ RTC_LOG(LS_INFO) << "[VESFW] " << __func__
+ << "(codec=" << codec_settings->ToString()
+ << ", settings={number_of_cores: "
+ << settings.number_of_cores
+ << ", max_payload_size: " << settings.max_payload_size
+ << "})";
// Store settings, in case we need to dynamically switch to the fallback
// encoder after a failed Encode call.
codec_settings_ = *codec_settings;
@@ -327,6 +336,8 @@
PrimeEncoder(current_encoder());
return ret;
}
+ RTC_LOG(LS_WARNING) << "[VESFW] Hardware encoder initialization failed with"
+ << " error code: " << WebRtcVideoCodecErrorToString(ret);
// Try to instantiate software codec.
if (InitFallbackEncoder(/*is_forced=*/false)) {
@@ -335,6 +346,8 @@
}
// Software encoder failed too, use original return code.
+ RTC_LOG(LS_WARNING)
+ << "[VESFW] Software fallback encoder initialization also failed.";
encoder_state_ = EncoderState::kUninitialized;
return ret;
}
diff --git a/media/engine/simulcast_encoder_adapter.cc b/media/engine/simulcast_encoder_adapter.cc
index 4853e68..cb31306 100644
--- a/media/engine/simulcast_encoder_adapter.cc
+++ b/media/engine/simulcast_encoder_adapter.cc
@@ -360,8 +360,14 @@
bool separate_encoders_needed =
!encoder_context->encoder().GetEncoderInfo().supports_simulcast ||
active_streams_count == 1;
+ RTC_LOG(LS_INFO) << "[SEA] InitEncode: total_streams_count: "
+ << total_streams_count_
+ << ", active_streams_count: " << active_streams_count
+ << ", separate_encoders_needed: "
+ << (separate_encoders_needed ? "true" : "false");
// Singlecast or simulcast with simulcast-capable underlaying encoder.
if (total_streams_count_ == 1 || !separate_encoders_needed) {
+ RTC_LOG(LS_INFO) << "[SEA] InitEncode: Single-encoder mode";
int ret = encoder_context->encoder().InitEncode(&codec_, settings);
if (ret >= 0) {
stream_contexts_.emplace_back(
@@ -377,7 +383,8 @@
encoder_context->Release();
if (total_streams_count_ == 1) {
- // Failed to initialize singlecast encoder.
+ RTC_LOG(LS_ERROR) << "[SEA] InitEncode: failed with error code: "
+ << WebRtcVideoCodecErrorToString(ret);
return ret;
}
}
@@ -405,10 +412,16 @@
/*is_lowest_quality_stream=*/stream_idx == lowest_quality_stream_idx,
/*is_highest_quality_stream=*/stream_idx == highest_quality_stream_idx);
+ RTC_LOG(LS_INFO) << "[SEA] Multi-encoder mode: initializing stream: "
+ << stream_idx << ", active: "
+ << (codec_.simulcastStream[stream_idx].active ? "true"
+ : "false");
int ret = encoder_context->encoder().InitEncode(&stream_codec, settings);
if (ret < 0) {
encoder_context.reset();
Release();
+ RTC_LOG(LS_ERROR) << "[SEA] InitEncode: failed with error code: "
+ << WebRtcVideoCodecErrorToString(ret);
return ret;
}
diff --git a/modules/video_coding/BUILD.gn b/modules/video_coding/BUILD.gn
index ce0a9f1..2208b9d 100644
--- a/modules/video_coding/BUILD.gn
+++ b/modules/video_coding/BUILD.gn
@@ -286,6 +286,7 @@
"include/video_codec_interface.cc",
"include/video_codec_interface.h",
"include/video_coding_defines.h",
+ "include/video_error_codes.cc",
"include/video_error_codes.h",
"video_coding_defines.cc",
]
diff --git a/modules/video_coding/include/video_error_codes.cc b/modules/video_coding/include/video_error_codes.cc
new file mode 100644
index 0000000..c806753
--- /dev/null
+++ b/modules/video_coding/include/video_error_codes.cc
@@ -0,0 +1,43 @@
+/*
+ * Copyright (c) 2024 The WebRTC project authors. All Rights Reserved.
+ *
+ * Use of this source code is governed by a BSD-style license
+ * that can be found in the LICENSE file in the root of the source
+ * tree. An additional intellectual property rights grant can be found
+ * in the file PATENTS. All contributing project authors may
+ * be found in the AUTHORS file in the root of the source tree.
+ */
+
+#include "modules/video_coding/include/video_error_codes.h"
+
+namespace webrtc {
+const char* WebRtcVideoCodecErrorToString(int32_t error_code) {
+ switch (error_code) {
+ case WEBRTC_VIDEO_CODEC_TARGET_BITRATE_OVERSHOOT:
+ return "WEBRTC_VIDEO_CODEC_TARGET_BITRATE_OVERSHOOT";
+ case WEBRTC_VIDEO_CODEC_OK_REQUEST_KEYFRAME:
+ return "WEBRTC_VIDEO_CODEC_OK_REQUEST_KEYFRAME";
+ case WEBRTC_VIDEO_CODEC_NO_OUTPUT:
+ return "WEBRTC_VIDEO_CODEC_NO_OUTPUT";
+ case WEBRTC_VIDEO_CODEC_ERROR:
+ return "WEBRTC_VIDEO_CODEC_ERROR";
+ case WEBRTC_VIDEO_CODEC_MEMORY:
+ return "WEBRTC_VIDEO_CODEC_MEMORY";
+ case WEBRTC_VIDEO_CODEC_ERR_PARAMETER:
+ return "WEBRTC_VIDEO_CODEC_ERR_PARAMETER";
+ case WEBRTC_VIDEO_CODEC_TIMEOUT:
+ return "WEBRTC_VIDEO_CODEC_TIMEOUT";
+ case WEBRTC_VIDEO_CODEC_UNINITIALIZED:
+ return "WEBRTC_VIDEO_CODEC_UNINITIALIZED";
+ case WEBRTC_VIDEO_CODEC_FALLBACK_SOFTWARE:
+ return "WEBRTC_VIDEO_CODEC_FALLBACK_SOFTWARE";
+ case WEBRTC_VIDEO_CODEC_ERR_SIMULCAST_PARAMETERS_NOT_SUPPORTED:
+ return "WEBRTC_VIDEO_CODEC_ERR_SIMULCAST_PARAMETERS_NOT_SUPPORTED";
+ case WEBRTC_VIDEO_CODEC_ENCODER_FAILURE:
+ return "WEBRTC_VIDEO_CODEC_ENCODER_FAILURE";
+ default:
+ return "WEBRTC_VIDEO_CODEC_UNKNOWN";
+ }
+}
+
+} // namespace webrtc
diff --git a/modules/video_coding/include/video_error_codes.h b/modules/video_coding/include/video_error_codes.h
index 17146ce..1634678 100644
--- a/modules/video_coding/include/video_error_codes.h
+++ b/modules/video_coding/include/video_error_codes.h
@@ -11,9 +11,7 @@
#ifndef MODULES_VIDEO_CODING_INCLUDE_VIDEO_ERROR_CODES_H_
#define MODULES_VIDEO_CODING_INCLUDE_VIDEO_ERROR_CODES_H_
-// NOTE: in sync with video_coding_module_defines.h
-
-// Define return values
+#include <stdint.h>
#define WEBRTC_VIDEO_CODEC_TARGET_BITRATE_OVERSHOOT 5
#define WEBRTC_VIDEO_CODEC_OK_REQUEST_KEYFRAME 4
@@ -28,4 +26,10 @@
#define WEBRTC_VIDEO_CODEC_ERR_SIMULCAST_PARAMETERS_NOT_SUPPORTED -15
#define WEBRTC_VIDEO_CODEC_ENCODER_FAILURE -16
+namespace webrtc {
+
+const char* WebRtcVideoCodecErrorToString(int32_t error_code);
+
+} // namespace webrtc
+
#endif // MODULES_VIDEO_CODING_INCLUDE_VIDEO_ERROR_CODES_H_
diff --git a/video/video_stream_encoder.cc b/video/video_stream_encoder.cc
index 3730f6e..6f398ec 100644
--- a/video/video_stream_encoder.cc
+++ b/video/video_stream_encoder.cc
@@ -937,6 +937,8 @@
void VideoStreamEncoder::ReconfigureEncoder() {
// Running on the encoder queue.
RTC_DCHECK(pending_encoder_reconfiguration_);
+ RTC_LOG(LS_INFO) << "[VSE] " << __func__
+ << " [encoder_config=" << encoder_config_.ToString() << "]";
bool encoder_reset_required = false;
if (pending_encoder_creation_) {
@@ -1154,37 +1156,38 @@
char log_stream_buf[4 * 1024];
rtc::SimpleStringBuilder log_stream(log_stream_buf);
- log_stream << "ReconfigureEncoder:\n";
- log_stream << "Simulcast streams:\n";
+ log_stream << "ReconfigureEncoder: simulcast streams: ";
for (size_t i = 0; i < codec.numberOfSimulcastStreams; ++i) {
- log_stream << i << ": " << codec.simulcastStream[i].width << "x"
- << codec.simulcastStream[i].height
- << " min_kbps: " << codec.simulcastStream[i].minBitrate
- << " target_kbps: " << codec.simulcastStream[i].targetBitrate
- << " max_kbps: " << codec.simulcastStream[i].maxBitrate
- << " max_fps: " << codec.simulcastStream[i].maxFramerate
- << " max_qp: " << codec.simulcastStream[i].qpMax
- << " num_tl: " << codec.simulcastStream[i].numberOfTemporalLayers
- << " active: "
- << (codec.simulcastStream[i].active ? "true" : "false") << "\n";
+ log_stream << "{" << i << ": " << codec.simulcastStream[i].width << "x"
+ << codec.simulcastStream[i].height << " "
+ << ScalabilityModeToString(
+ codec.simulcastStream[i].GetScalabilityMode())
+ << ", min_kbps: " << codec.simulcastStream[i].minBitrate
+ << ", target_kbps: " << codec.simulcastStream[i].targetBitrate
+ << ", max_kbps: " << codec.simulcastStream[i].maxBitrate
+ << ", max_fps: " << codec.simulcastStream[i].maxFramerate
+ << ", max_qp: " << codec.simulcastStream[i].qpMax << ", num_tl: "
+ << codec.simulcastStream[i].numberOfTemporalLayers
+ << ", active: "
+ << (codec.simulcastStream[i].active ? "true" : "false") << "}";
}
if (encoder_config_.codec_type == kVideoCodecVP9 ||
encoder_config_.codec_type == kVideoCodecAV1) {
- log_stream << "Spatial layers:\n";
+ log_stream << ", spatial layers: ";
for (int i = 0; i < GetNumSpatialLayers(codec); ++i) {
- log_stream << i << ": " << codec.spatialLayers[i].width << "x"
+ log_stream << "{" << i << ": " << codec.spatialLayers[i].width << "x"
<< codec.spatialLayers[i].height
- << " min_kbps: " << codec.spatialLayers[i].minBitrate
- << " target_kbps: " << codec.spatialLayers[i].targetBitrate
- << " max_kbps: " << codec.spatialLayers[i].maxBitrate
- << " max_fps: " << codec.spatialLayers[i].maxFramerate
- << " max_qp: " << codec.spatialLayers[i].qpMax
- << " num_tl: " << codec.spatialLayers[i].numberOfTemporalLayers
- << " active: "
- << (codec.spatialLayers[i].active ? "true" : "false") << "\n";
+ << ", min_kbps: " << codec.spatialLayers[i].minBitrate
+ << ", target_kbps: " << codec.spatialLayers[i].targetBitrate
+ << ", max_kbps: " << codec.spatialLayers[i].maxBitrate
+ << ", max_fps: " << codec.spatialLayers[i].maxFramerate
+ << ", max_qp: " << codec.spatialLayers[i].qpMax << ", num_tl: "
+ << codec.spatialLayers[i].numberOfTemporalLayers
+ << ", active: "
+ << (codec.spatialLayers[i].active ? "true" : "false") << "}";
}
}
- RTC_LOG(LS_INFO) << log_stream.str();
+ RTC_LOG(LS_INFO) << "[VSE] " << log_stream.str();
codec.startBitrate = std::max(encoder_target_bitrate_bps_.value_or(0) / 1000,
codec.minBitrate);
@@ -1319,7 +1322,7 @@
<< " max frame rate " << codec.maxFramerate
<< " max payload size " << max_data_payload_length_;
} else {
- RTC_LOG(LS_ERROR) << "Failed to configure encoder.";
+ RTC_LOG(LS_ERROR) << "[VSE] Failed to configure encoder.";
rate_allocator_ = nullptr;
}
@@ -1917,7 +1920,7 @@
stream_resource_manager_.ConfigureQualityScaler(info);
stream_resource_manager_.ConfigureBandwidthQualityScaler(info);
- RTC_LOG(LS_INFO) << "Encoder info changed to " << info.ToString();
+ RTC_LOG(LS_INFO) << "[VSE] Encoder info changed to " << info.ToString();
}
if (bitrate_adjuster_) {
