// Copyright (c) 2012 The Chromium Authors. All rights reserved. // Use of this source code is governed by a BSD-style license that can be // found in the LICENSE file. #include "services/audio/input_sync_writer.h" #include #include #include "base/format_macros.h" #include "base/logging.h" #include "base/metrics/histogram_macros.h" #include "base/strings/stringprintf.h" #include "base/trace_event/trace_event.h" #include "build/build_config.h" namespace audio { namespace { // Used to log if any audio glitches have been detected during an audio session. // Elements in this enum should not be added, deleted or rearranged. enum AudioGlitchResult { AUDIO_CAPTURER_NO_AUDIO_GLITCHES = 0, AUDIO_CAPTURER_AUDIO_GLITCHES = 1, AUDIO_CAPTURER_AUDIO_GLITCHES_MAX = AUDIO_CAPTURER_AUDIO_GLITCHES }; } // namespace InputSyncWriter::OverflowData::OverflowData( double volume, bool key_pressed, base::TimeTicks capture_time, std::unique_ptr audio_bus) : volume_(volume), key_pressed_(key_pressed), capture_time_(capture_time), audio_bus_(std::move(audio_bus)) {} InputSyncWriter::OverflowData::~OverflowData() {} InputSyncWriter::OverflowData::OverflowData(InputSyncWriter::OverflowData&&) = default; InputSyncWriter::OverflowData& InputSyncWriter::OverflowData::operator=( InputSyncWriter::OverflowData&& other) = default; InputSyncWriter::InputSyncWriter( base::RepeatingCallback log_callback, base::MappedReadOnlyRegion shared_memory, std::unique_ptr socket, uint32_t shared_memory_segment_count, const media::AudioParameters& params) : log_callback_(std::move(log_callback)), socket_(std::move(socket)), shared_memory_region_(std::move(shared_memory.region)), shared_memory_mapping_(std::move(shared_memory.mapping)), shared_memory_segment_size_( (CHECK(shared_memory_segment_count > 0), shared_memory_mapping_.size() / shared_memory_segment_count)), creation_time_(base::TimeTicks::Now()), audio_bus_memory_size_(media::AudioBus::CalculateMemorySize(params)) { // We use CHECKs since this class is used for IPC. DCHECK(log_callback_); CHECK(socket_); CHECK(shared_memory_region_.IsValid()); CHECK(shared_memory_mapping_.IsValid()); CHECK_EQ(shared_memory_segment_size_ * shared_memory_segment_count, shared_memory_mapping_.size()); CHECK_EQ(shared_memory_segment_size_, audio_bus_memory_size_ + sizeof(media::AudioInputBufferParameters)); DVLOG(1) << "shared memory size: " << shared_memory_mapping_.size(); DVLOG(1) << "shared memory segment count: " << shared_memory_segment_count; DVLOG(1) << "audio bus memory size: " << audio_bus_memory_size_; audio_buses_.resize(shared_memory_segment_count); // Create vector of audio buses by wrapping existing blocks of memory. uint8_t* ptr = static_cast(shared_memory_mapping_.memory()); CHECK(ptr); for (auto& bus : audio_buses_) { CHECK_EQ(0U, reinterpret_cast(ptr) & (media::AudioBus::kChannelAlignment - 1)); media::AudioInputBuffer* buffer = reinterpret_cast(ptr); bus = media::AudioBus::WrapMemory(params, buffer->audio); ptr += shared_memory_segment_size_; } } InputSyncWriter::~InputSyncWriter() { // We log the following: // - Percentage of data written to fifo (and not to shared memory). // - Percentage of data dropped (fifo reached max size or socket buffer full). // - Glitch yes/no (at least 1 drop). // // Subtract 'trailing' counts that will happen if the renderer process was // killed or e.g. the page refreshed while the input device was open etc. // This trims off the end of both the error and write counts so that we // preserve the proportion of counts before the teardown period. We pick // the largest trailing count as the time we consider that the trailing errors // begun, and subract that from the total write count. DCHECK_LE(trailing_write_to_fifo_count_, write_to_fifo_count_); DCHECK_LE(trailing_write_to_fifo_count_, write_count_); DCHECK_LE(trailing_write_error_count_, write_error_count_); DCHECK_LE(trailing_write_error_count_, write_count_); write_to_fifo_count_ -= trailing_write_to_fifo_count_; write_error_count_ -= trailing_write_error_count_; write_count_ -= std::max(trailing_write_to_fifo_count_, trailing_write_error_count_); if (write_count_ == 0) return; UMA_HISTOGRAM_PERCENTAGE("Media.AudioCapturerMissedReadDeadline", 100.0 * write_to_fifo_count_ / write_count_); UMA_HISTOGRAM_PERCENTAGE("Media.AudioCapturerDroppedData", 100.0 * write_error_count_ / write_count_); UMA_HISTOGRAM_ENUMERATION("Media.AudioCapturerAudioGlitches", write_error_count_ == 0 ? AUDIO_CAPTURER_NO_AUDIO_GLITCHES : AUDIO_CAPTURER_AUDIO_GLITCHES, AUDIO_CAPTURER_AUDIO_GLITCHES_MAX + 1); std::string log_string = base::StringPrintf( "AISW: number of detected audio glitches: %" PRIuS " out of %" PRIuS, write_error_count_, write_count_); log_callback_.Run(log_string); } // static std::unique_ptr InputSyncWriter::Create( base::RepeatingCallback log_callback, uint32_t shared_memory_segment_count, const media::AudioParameters& params, base::CancelableSyncSocket* foreign_socket) { // Having no shared memory doesn't make sense, so fail creation in that case. if (shared_memory_segment_count == 0) return nullptr; base::CheckedNumeric requested_memory_size = ComputeAudioInputBufferSizeChecked(params, shared_memory_segment_count); if (!requested_memory_size.IsValid()) return nullptr; // Make sure we can share the memory read-only with the client. auto shared_memory = base::ReadOnlySharedMemoryRegion::Create( requested_memory_size.ValueOrDie()); if (!shared_memory.IsValid()) return nullptr; auto socket = std::make_unique(); if (!base::CancelableSyncSocket::CreatePair(socket.get(), foreign_socket)) { return nullptr; } return std::make_unique( std::move(log_callback), std::move(shared_memory), std::move(socket), shared_memory_segment_count, params); } base::ReadOnlySharedMemoryRegion InputSyncWriter::TakeSharedMemoryRegion() { DCHECK(shared_memory_region_.IsValid()); return std::move(shared_memory_region_); } void InputSyncWriter::Write(const media::AudioBus* data, double volume, bool key_pressed, base::TimeTicks capture_time) { TRACE_EVENT1("audio", "InputSyncWriter::Write", "capture time (ms)", (capture_time - base::TimeTicks()).InMillisecondsF()); ++write_count_; CheckTimeSinceLastWrite(); // Check that the renderer side has read data so that we don't overwrite data // that hasn't been read yet. The renderer side sends a signal over the socket // each time it has read data. Here, we read those verifications before // writing. We verify that each buffer index is in sequence. size_t number_of_indices_available = socket_->Peek() / sizeof(uint32_t); if (number_of_indices_available > 0) { auto indices = std::make_unique(number_of_indices_available); size_t bytes_received = socket_->Receive( &indices[0], number_of_indices_available * sizeof(indices[0])); CHECK_EQ(number_of_indices_available * sizeof(indices[0]), bytes_received); for (size_t i = 0; i < number_of_indices_available; ++i) { ++next_read_buffer_index_; CHECK_EQ(indices[i], next_read_buffer_index_); CHECK_GT(number_of_filled_segments_, 0u); --number_of_filled_segments_; } } bool write_error = !WriteDataFromFifoToSharedMemory(); // Write the current data to the shared memory if there is room, otherwise // put it in the fifo. if (number_of_filled_segments_ < audio_buses_.size()) { WriteParametersToCurrentSegment(volume, key_pressed, capture_time); // Copy data into shared memory using pre-allocated audio buses. data->CopyTo(audio_buses_[current_segment_id_].get()); if (!SignalDataWrittenAndUpdateCounters()) write_error = true; trailing_write_to_fifo_count_ = 0; } else { if (!PushDataToFifo(data, volume, key_pressed, capture_time)) write_error = true; ++write_to_fifo_count_; ++trailing_write_to_fifo_count_; } // Increase write error counts if error, or reset the trailing error counter // if all write operations went well (no data dropped). if (write_error) { ++write_error_count_; ++trailing_write_error_count_; TRACE_EVENT_INSTANT0("audio", "InputSyncWriter write error", TRACE_EVENT_SCOPE_THREAD); } else { trailing_write_error_count_ = 0; } } void InputSyncWriter::Close() { socket_->Close(); } void InputSyncWriter::CheckTimeSinceLastWrite() { #if !defined(OS_ANDROID) static const base::TimeDelta kLogDelayThreadhold = base::TimeDelta::FromMilliseconds(500); base::TimeTicks new_write_time = base::TimeTicks::Now(); std::ostringstream oss; if (last_write_time_.is_null()) { // This is the first time Write is called. base::TimeDelta interval = new_write_time - creation_time_; oss << "AISW::Write: audio input data received for the first time: delay " "= " << interval.InMilliseconds() << "ms"; } else { base::TimeDelta interval = new_write_time - last_write_time_; if (interval > kLogDelayThreadhold) { oss << "AISW::Write: audio input data delay unexpectedly long: delay = " << interval.InMilliseconds() << "ms"; } } const std::string log_message = oss.str(); if (!log_message.empty()) { log_callback_.Run(log_message); } last_write_time_ = new_write_time; #endif } bool InputSyncWriter::PushDataToFifo(const media::AudioBus* data, double volume, bool key_pressed, base::TimeTicks capture_time) { TRACE_EVENT1("audio", "InputSyncWriter::PushDataToFifo", "capture time (ms)", (capture_time - base::TimeTicks()).InMillisecondsF()); if (overflow_data_.size() == kMaxOverflowBusesSize) { // We use |write_error_count_| for capping number of log messages. // |write_error_count_| also includes socket Send() errors, but those should // be rare. TRACE_EVENT_INSTANT0("audio", "InputSyncWriter::PushDataToFifo - overflow", TRACE_EVENT_SCOPE_THREAD); if (write_error_count_ <= 50 && write_error_count_ % 10 == 0) { static const char* error_message = "AISW: No room in fifo."; LOG(WARNING) << error_message; log_callback_.Run(error_message); if (write_error_count_ == 50) { static const char* cap_error_message = "AISW: Log cap reached, suppressing further fifo overflow logs."; LOG(WARNING) << cap_error_message; log_callback_.Run(error_message); } } return false; } if (overflow_data_.empty()) { static const char* message = "AISW: Starting to use fifo."; log_callback_.Run(message); } // Push data to fifo. std::unique_ptr audio_bus = media::AudioBus::Create(data->channels(), data->frames()); data->CopyTo(audio_bus.get()); overflow_data_.emplace_back(volume, key_pressed, capture_time, std::move(audio_bus)); DCHECK_LE(overflow_data_.size(), static_cast(kMaxOverflowBusesSize)); return true; } bool InputSyncWriter::WriteDataFromFifoToSharedMemory() { TRACE_EVENT0("audio", "InputSyncWriter::WriteDataFromFifoToSharedMemory"); if (overflow_data_.empty()) return true; const size_t segment_count = audio_buses_.size(); bool write_error = false; auto data_it = overflow_data_.begin(); while (data_it != overflow_data_.end() && number_of_filled_segments_ < segment_count) { // Write parameters to shared memory. WriteParametersToCurrentSegment(data_it->volume_, data_it->key_pressed_, data_it->capture_time_); // Copy data from the fifo into shared memory using pre-allocated audio // buses. data_it->audio_bus_->CopyTo(audio_buses_[current_segment_id_].get()); if (!SignalDataWrittenAndUpdateCounters()) write_error = true; ++data_it; } // Erase all copied data from fifo. overflow_data_.erase(overflow_data_.begin(), data_it); if (overflow_data_.empty()) { static const char* message = "AISW: Fifo emptied."; log_callback_.Run(message); } return !write_error; } void InputSyncWriter::WriteParametersToCurrentSegment( double volume, bool key_pressed, base::TimeTicks capture_time) { TRACE_EVENT1("audio", "WriteParametersToCurrentSegment", "capture time (ms)", (capture_time - base::TimeTicks()).InMillisecondsF()); uint8_t* ptr = static_cast(shared_memory_mapping_.memory()); CHECK_LT(current_segment_id_, audio_buses_.size()); ptr += current_segment_id_ * shared_memory_segment_size_; auto* buffer = reinterpret_cast(ptr); buffer->params.volume = volume; buffer->params.size = audio_bus_memory_size_; buffer->params.key_pressed = key_pressed; buffer->params.capture_time_us = (capture_time - base::TimeTicks()).InMicroseconds(); buffer->params.id = next_buffer_id_; } bool InputSyncWriter::SignalDataWrittenAndUpdateCounters() { if (socket_->Send(¤t_segment_id_, sizeof(current_segment_id_)) != sizeof(current_segment_id_)) { // Ensure we don't log consecutive errors as this can lead to a large // amount of logs. if (!had_socket_error_) { had_socket_error_ = true; static const char* error_message = "AISW: No room in socket buffer."; PLOG(WARNING) << error_message; log_callback_.Run(error_message); TRACE_EVENT_INSTANT0("audio", "InputSyncWriter: No room in socket buffer", TRACE_EVENT_SCOPE_THREAD); } return false; } else { had_socket_error_ = false; } if (++current_segment_id_ >= audio_buses_.size()) current_segment_id_ = 0; ++number_of_filled_segments_; CHECK_LE(number_of_filled_segments_, audio_buses_.size()); ++next_buffer_id_; return true; } } // namespace audio