From 414c94290af044991c7e2d1aadbec9dafb9ee64e Mon Sep 17 00:00:00 2001 From: henrika Date: Wed, 14 Feb 2024 18:08:26 +0100 Subject: [PATCH] Reland "Extends WebRTC logs for software encoder fallback" MIME-Version: 1.0 Content-Type: text/plain; charset=UTF-8 Content-Transfer-Encoding: 8bit This is a reland of commit 050ffefd854f8a57071992238723259e9ae0d85a Original change's description: > 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 > Reviewed-by: Ilya Nikolaevskiy > Reviewed-by: Henrik Boström > Cr-Commit-Position: refs/heads/main@{#41733} NOTRY=true Bug: b/322132132 Change-Id: I25dd34b9ba59ea8502e47b4c89cd111430636e08 Reviewed-on: https://webrtc-review.googlesource.com/c/src/+/339680 Reviewed-by: Mirko Bonadei Commit-Queue: Henrik Andreassson Cr-Commit-Position: refs/heads/main@{#41736} --- api/video_codecs/video_codec.cc | 30 +++++++++++ api/video_codecs/video_codec.h | 4 ++ ...video_encoder_software_fallback_wrapper.cc | 18 ++++++- media/engine/simulcast_encoder_adapter.cc | 16 +++++- modules/video_coding/BUILD.gn | 2 + .../video_coding/include/video_error_codes.h | 4 -- .../include/video_error_codes_utils.cc | 46 ++++++++++++++++ .../include/video_error_codes_utils.h | 22 ++++++++ video/video_stream_encoder.cc | 53 ++++++++++--------- 9 files changed, 163 insertions(+), 32 deletions(-) create mode 100644 modules/video_coding/include/video_error_codes_utils.cc create mode 100644 modules/video_coding/include/video_error_codes_utils.h diff --git a/api/video_codecs/video_codec.cc b/api/video_codecs/video_codec.cc index 39a345d699..82c9bfc8ea 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 @@ VideoCodec::VideoCodec() 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 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 a596af1528..e48ffd4b5f 100644 --- a/api/video_codecs/video_codec.h +++ b/api/video_codecs/video_codec.h @@ -141,6 +141,9 @@ class RTC_EXPORT VideoCodec { 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 @@ class RTC_EXPORT VideoCodec { 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 d35c9f9950..e50b5086e8 100644 --- a/api/video_codecs/video_encoder_software_fallback_wrapper.cc +++ b/api/video_codecs/video_encoder_software_fallback_wrapper.cc @@ -28,6 +28,7 @@ #include "api/video_codecs/video_encoder.h" #include "media/base/video_common.h" #include "modules/video_coding/include/video_error_codes.h" +#include "modules/video_coding/include/video_error_codes_utils.h" #include "modules/video_coding/utility/simulcast_utility.h" #include "rtc_base/checks.h" #include "rtc_base/experiments/field_trial_parser.h" @@ -264,14 +265,17 @@ void VideoEncoderSoftwareFallbackWrapper::PrimeEncoder( } 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 +309,12 @@ void VideoEncoderSoftwareFallbackWrapper::SetFecControllerOverride( 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 +337,8 @@ int32_t VideoEncoderSoftwareFallbackWrapper::InitEncode( 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 +347,8 @@ int32_t VideoEncoderSoftwareFallbackWrapper::InitEncode( } // 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 4853e68996..642fe31e90 100644 --- a/media/engine/simulcast_encoder_adapter.cc +++ b/media/engine/simulcast_encoder_adapter.cc @@ -32,6 +32,7 @@ #include "media/base/media_constants.h" #include "media/base/video_common.h" #include "modules/video_coding/include/video_error_codes.h" +#include "modules/video_coding/include/video_error_codes_utils.h" #include "modules/video_coding/utility/simulcast_rate_allocator.h" #include "rtc_base/checks.h" #include "rtc_base/experiments/rate_control_settings.h" @@ -360,8 +361,14 @@ int SimulcastEncoderAdapter::InitEncode( 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 +384,8 @@ int SimulcastEncoderAdapter::InitEncode( 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 +413,16 @@ int SimulcastEncoderAdapter::InitEncode( /*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 ce0a9f1e5e..31de2956f3 100644 --- a/modules/video_coding/BUILD.gn +++ b/modules/video_coding/BUILD.gn @@ -287,6 +287,8 @@ rtc_library("video_codec_interface") { "include/video_codec_interface.h", "include/video_coding_defines.h", "include/video_error_codes.h", + "include/video_error_codes_utils.cc", + "include/video_error_codes_utils.h", "video_coding_defines.cc", ] deps = [ diff --git a/modules/video_coding/include/video_error_codes.h b/modules/video_coding/include/video_error_codes.h index 17146ce205..d7d54f3989 100644 --- a/modules/video_coding/include/video_error_codes.h +++ b/modules/video_coding/include/video_error_codes.h @@ -11,10 +11,6 @@ #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 - #define WEBRTC_VIDEO_CODEC_TARGET_BITRATE_OVERSHOOT 5 #define WEBRTC_VIDEO_CODEC_OK_REQUEST_KEYFRAME 4 #define WEBRTC_VIDEO_CODEC_NO_OUTPUT 1 diff --git a/modules/video_coding/include/video_error_codes_utils.cc b/modules/video_coding/include/video_error_codes_utils.cc new file mode 100644 index 0000000000..7e2c08d518 --- /dev/null +++ b/modules/video_coding/include/video_error_codes_utils.cc @@ -0,0 +1,46 @@ +/* + * 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_utils.h" + +#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_utils.h b/modules/video_coding/include/video_error_codes_utils.h new file mode 100644 index 0000000000..ae17e29636 --- /dev/null +++ b/modules/video_coding/include/video_error_codes_utils.h @@ -0,0 +1,22 @@ +/* + * 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. + */ + +#ifndef MODULES_VIDEO_CODING_INCLUDE_VIDEO_ERROR_CODES_UTILS_H_ +#define MODULES_VIDEO_CODING_INCLUDE_VIDEO_ERROR_CODES_UTILS_H_ + +#include + +namespace webrtc { + +const char* WebRtcVideoCodecErrorToString(int32_t error_code); + +} // namespace webrtc + +#endif // MODULES_VIDEO_CODING_INCLUDE_VIDEO_ERROR_CODES_UTILS_H_ diff --git a/video/video_stream_encoder.cc b/video/video_stream_encoder.cc index ae55bfda23..73cd7826f9 100644 --- a/video/video_stream_encoder.cc +++ b/video/video_stream_encoder.cc @@ -937,6 +937,8 @@ void VideoStreamEncoder::ConfigureEncoder(VideoEncoderConfig config, 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 @@ void VideoStreamEncoder::ReconfigureEncoder() { 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 @@ void VideoStreamEncoder::ReconfigureEncoder() { << " 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 @@ void VideoStreamEncoder::EncodeVideoFrame(const VideoFrame& video_frame, 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_) {